picamera icon indicating copy to clipboard operation
picamera copied to clipboard

stop_recording fails to return and locks up depending on recording options

Open dans98 opened this issue 5 years ago • 10 comments

I encountered this issue while running an official V2.1 camera module on a V1.1 Pi zero W. both units where purchased from an approved re-seller. I did a fresh install and its details are as follows.

pi@raspberrypi:~ $ uname -a Linux raspberrypi 4.19.97+ #1294 Thu Jan 30 13:10:54 GMT 2020 armv6l GNU/Linux

pi@raspberrypi:~ $ cat /etc/debian_version 10.3

cat /etc/os-release pi@raspberrypi:~ $ cat /etc/os-release PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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"

pi@raspberrypi:~ $ apt-cache policy python3-picamera python3-picamera: Installed: 1.13 Candidate: 1.13 Version table: *** 1.13 500 500 http://archive.raspberrypi.org/debian buster/main armhf Packages 100 /var/lib/dpkg/status

I encountered this issue on a mildly complex project, but after several iterations I have been able to simplify and condense my code down into the test script below. You can comment/un-comment the the various test cases between runs.

when a test case fails, the active script locks up and you need to open a new ssh connection and restart the pi. To be clear the pi itself is fine, and you can run other python applications in other ssh connections, but to release the camera module you have to restart.

from io import BytesIO
import picamera
import logging

try:
    camera = picamera.PiCamera(sensor_mode=4, resolution='1640x1232', framerate=40)
    op = BytesIO()
    iterations = 250

    for i in range(1, iterations+1):
        print('')
        print('iteration : ' + str(i))
        camera.start_recording(op, splitter_port=0, format='mjpeg', bitrate=25000000) #test case 1
        #camera.start_recording(op, splitter_port=0, format='mjpeg', bitrate=18000000, resize=(1230,924)) # test case 2
        #camera.start_recording(op, splitter_port=0, format='mjpeg', bitrate=10000000, resize=(820,616)) #test case 3
        #camera.start_recording(op, splitter_port=0, format='mjpeg', bitrate=4000000, resize=(410,308)) #test case 4
        print('start_recording')
        camera.wait_recording(timeout=1, splitter_port=0)
        print('wait_recording')
        camera.stop_recording(splitter_port=0)
        print('stop_recording')
        op.seek(0)
        op.truncate()

except KeyboardInterrupt:
    pass
except Exception as e:
    logging.error('issue', exc_info=1)
finally:
    camera.close()

with sensor_mode=4, resolution='1640x1232' and framerate=40 the test cases give the following results.

  1. works correctly no matter how many iterations are run
  2. fails to return the 1st iteration, no exception raised
  3. fails to return the 4th iteration, no exception raised
  4. fails to return the 1st iteration, no exception raised

with the framerate lowered to 30

  1. works correctly no matter how many iterations are run
  2. fails to return the 1st iteration, no exception raised
  3. fails to return the 4th iteration, no exception raised
  4. works correctly no matter how many iterations are run

with the framerate lowered to 25

  1. works correctly no matter how many iterations are run
  2. works correctly no matter how many iterations are run
  3. works correctly no matter how many iterations are run
  4. works correctly no matter how many iterations are run

For my more complex test cases fps had to drop to 24, for everything to run smoothly.

Now here is the rub, If I take the fps back to 40 and remove the resizing from test cases 2 through 4 this is what I get.

  1. works correctly no matter how many iterations are run (as expected)
  2. works correctly no matter how many iterations are run
  3. works correctly no matter how many iterations are run
  4. works correctly no matter how many iterations are run

I'm not sure if the issue is at the Python, MMAL, or GPU level, but something is very odd. Some how it ties into the fps and resize options. what's even odder, is that even with the settings from the original script, I was able to generate a video stream out to a browser at 40 fps no matter what resize was set to. The failure only ever happens with stop_recording.

dans98 avatar Apr 13 '20 20:04 dans98

Wow I just started having this issue also on a somewhat bigger/complex project.

The same thing happens to me when I'm dynamically opening and closing recordings with different resize options. I don't change the framerate though.

I also use set motion_output on all of them but probably unrelated as this example shows the same issue without the motion output set.

I'm not sure how alive this project is anymore though :( It is actually so good, @waveform80 please come back :)

Esser50K avatar Apr 25 '20 14:04 Esser50K

More info:

I tried replicating my problem on the interactive console. I was surprised it was always working. The only differences to my "real" program were the extra options other than the resolution. So resize does not seem to be the culprit here. I also had set some h264 specific options and the bitrate. Didn't investigate further as I have something working for my use case, but I would guess it has something to do with the bitrate.

Esser50K avatar Apr 26 '20 08:04 Esser50K

@Esser420 I haven't been able to dig into this to much because life has been a little crazy with what is going on in the world right now.

For my project the frame-rate is the same the only thing that changes is the resolution and bit-rate. In this old bug @6by9 mentions that mjpeg and h.264 have different architectures, and that might be why you are seeing a difference.

I've only started to dig into the issue, but I do wonder if it might be related to buffer size issues that @waveform80 and @6by9 have mentioned on a few tickets.

for example this, sounds about like what i am seeing. https://github.com/waveform80/picamera/issues/315#issuecomment-238353837

It's https://github.com/waveform80/picamera/blob/master/picamera/mmalobj.py#L760 that is going to be the problem. The default buffer size off video_encode is 64kB. The MJPEG codec is pretty shonky and will stall badly if it can't get rid of the output data. Disable whilst it still has output data queued and it is game over :-(

Honestly This biggest issue I'll probably face with tracking down whatever the issue happens to be, is that this isn't a simple scenario (no exceptions etc), and I don't have any intimate knowledge of the code base.

dans98 avatar Apr 26 '20 23:04 dans98

No luck so far, I tried increasing the output buffer size, and that didn't help at all.

I also tried using the isp resizer instead of the vpu resizer but i got a runtime error I don't understand how to fix.

code:

from io import BytesIO
from picamera import mmal, mmalobj as mo
import picamera
import logging

class MyEncoder(picamera.PiCookedVideoEncoder):
    def start(self, output, motion_output=None):
        super(MyEncoder, self).start(output, motion_output)
        frame = self.output_port._get_framesize()
        self.output_port._set_buffer_size(frame.width*frame.height*3)

    def _create_resizer(self, width, height):
        self.resizer = mo.MMALISPResizer()
        self.resizer.connect(self.input_port)
        self.resizer.outputs[0].copy_from(self.resizer.inputs[0])
        self.resizer.outputs[0].format = mmal.MMAL_ENCODING_I420
        self.resizer.outputs[0].framesize = (width, height)
        self.resizer.outputs[0].commit()

class MyCamera(picamera.PiCamera):
    def _get_video_encoder(self, *args, **kwargs):
        return MyEncoder(self, *args, **kwargs)


try:
    camera = MyCamera(sensor_mode=4, resolution='1640x1232', framerate=40)
    op = BytesIO()
    iterations = 10

    for i in range(1, iterations+1):
        print('')
        print('iteration : ' + str(i))
        #camera.start_recording(op, splitter_port=0, format='mjpeg', bitrate=25000000) #test case 1
        camera.start_recording(op, splitter_port=0, format='mjpeg', bitrate=18000000, resize=(1230,924)) # test case 2
        #camera.start_recording(op, splitter_port=0, format='mjpeg', bitrate=10000000, resize=(820,616)) #test case 3
        #camera.start_recording(op, splitter_port=0, format='mjpeg', bitrate=4000000, resize=(410,308)) #test case 4
        print('start_recording')
        camera.wait_recording(timeout=1, splitter_port=0)
        print('wait_recording')
        camera.stop_recording(splitter_port=0)
        print('stop_recording')
        op.seek(0)
        op.truncate()

except KeyboardInterrupt:
    pass
except Exception as e:
    logging.error('issue', exc_info=1)
finally:
    camera.close()

error:

ERROR:root:issue
Traceback (most recent call last):
  File "/home/pi/code/testing/run4.py", line 39, in <module>
    camera.start_recording(op, splitter_port=0, format='mjpeg', bitrate=18000000, resize=(1230,924)) # test case 2
  File "/usr/lib/python3/dist-packages/picamera/camera.py", line 1046, in start_recording
    camera_port, output_port, format, resize, **options)
  File "/home/pi/code/testing/run4.py", line 27, in _get_video_encoder
    return MyEncoder(self, *args, **kwargs)
  File "/usr/lib/python3/dist-packages/picamera/encoders.py", line 601, in __init__
    parent, camera_port, input_port, format, resize, **options)
  File "/usr/lib/python3/dist-packages/picamera/encoders.py", line 186, in __init__
    self._create_resizer(*mo.to_resolution(resize))
  File "/home/pi/code/testing/run4.py", line 18, in _create_resizer
    self.resizer = mo.MMALISPResizer()
  File "/usr/lib/python3/dist-packages/picamera/mmalobj.py", line 2396, in __init__
    super(MMALComponent, self).__init__()
  File "/usr/lib/python3/dist-packages/picamera/mmalobj.py", line 645, in __init__
    self.component_type))
picamera.exc.PiCameraRuntimeError: Expected 1 outputs but found 3 on component b'vc.ril.isp'

dans98 avatar Apr 28 '20 02:04 dans98

This comment by @6by9 seems to explain why I can't get MMALISPResizer to work no matter what I try.

dans98 avatar Apr 30 '20 21:04 dans98

Looks like I faced with the same issue, but using different route

mikhailkin avatar May 17 '20 19:05 mikhailkin

Pinging the issue, to let the rpi developers know this is still an issue that needs fixed.

dans98 avatar Sep 30 '20 07:09 dans98

Adding here, this is a problem we are currently experiencing too. I'll have to investigate more to be sure this is the case, but I think the issue we face is very similar to this one, if not identical.

gromain avatar Oct 06 '20 19:10 gromain

I just tested with your script and I saw the exact same problem pops up. Error definitely reproduced then. @waveform80 is there anything that can be done to help debugging this issue?

gromain avatar Oct 07 '20 07:10 gromain

Same issue. In addition to stop_recording getting hung, nothing short of a complete reboot will bring back camera functionality.

rshom avatar Nov 20 '23 21:11 rshom