[libcamera-devel] [PATCH v2 00/27] libcamera: Handle fallout of FrameBuffer offset support

Mon Sep 6 14:16:11 CEST 2021

Hi Kieran,

On Mon, Sep 06, 2021 at 11:43:15AM +0100, Kieran Bingham wrote:
> On 06/09/2021 11:08, Umang Jain wrote:
> > On 9/6/21 7:30 AM, Laurent Pinchart wrote:
> >> Hello everybody,
> >>
> >> This patch series started as an investigation of a qcam failure with
> >> IPU3 after the merge of the FrameBuffer offset support. While a hack in
> >> qcam would be possible, I decided to instead address the core issue and
> >> fix it in V4L2VideoDevice.
> >>
> >> Compared to v1, the series now includes fixes for cam and qcam in
> >> addition to the changes needed in the libcamera core. They have been
> >> tested with the Raspberry Pi, IPU3, VIMC and UVC pipeline handlers.
> >>
> >> The GStreamer element seems to work fine without any change required.
> >> The V4L2 compatibility layer is still broken, and I haven't tested the
> >> Android HAL yet (any volunteer ?).
> > 
> > I am applied this series on top of master and tested on nautilus.
> > Streaming seems fine to me, although it was appearing more choppy than
> > usual.
> > 
> > Now that I see, entire nautilus seems laggy to respond in general. One
> > "Chrome" process hogging 50% CPU, seems like a transient issue.
> > 
> > So, streaming seems fine on multiple runs, with multiple resolutions
> > selections (from the camera-app menu), however, requesting MJPEG
> > (shutter-click) results in a segfault.
> > 
> > The stack trace is below:
> > 
> > [0:24:11.415660787] [10635] DEBUG HAL camera_device.cpp:941
> > '\_SB_.PCI0.I2C2.CAM0': Queueing request 140736750235824 with 2 streams
> > [0:24:11.415858538] [10635] DEBUG Buffer framebuffer.cpp:249 Buffer is
> > not contiguous
> > [0:24:11.415905500] [10635] DEBUG HAL camera_device.cpp:980
> > '\_SB_.PCI0.I2C2.CAM0': 0 - (4160x3104)[0x00000023] -> (4160x3104)[NV12]
> > (direct)
> > [0:24:11.415943620] [10635] DEBUG HAL camera_device.cpp:966
> > '\_SB_.PCI0.I2C2.CAM0': 1 - (4160x3104)[0x00000021] -> (4160x3104)[NV12]
> > (mapped)
> > [0:24:11.416461639] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video0[37:cap]: Queueing buffer 3
> > [0:24:11.428903141] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video0[37:cap]: Dequeuing buffer 2
> > [0:24:11.429095316] [10643] DEBUG IPU3Awb awb.cpp:331 Color temperature
> > estimated: 6644
> > [0:24:11.429563781] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:237 frame 193 started
> > [0:24:11.429627478] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:272 Setting Exposure to 269 at index 193
> > [0:24:11.429683048] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video6[25:cap]: Queueing buffer 1
> > [0:24:11.436615191] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video5[27:out]: Queueing buffer 2
> > [0:24:11.436718629] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video8[28:cap]: Queueing buffer 2
> > [0:24:11.436799420] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video4[24:out]: Queueing buffer 2
> > [0:24:11.457388821] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video4[24:out]: Dequeuing buffer 1
> > [0:24:11.457948159] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video6[25:cap]: Dequeuing buffer 0
> > [0:24:11.458257692] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video5[27:out]: Dequeuing buffer 2
> > [0:24:11.458525315] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video8[28:cap]: Dequeuing buffer 1
> > [0:24:11.458968848] [10643] DEBUG IPU3Awb awb.cpp:270 Valid zones: 186
> > [0:24:11.459005634] [10643] DEBUG IPU3Awb awb.cpp:224 Grey world AWB
> > [0:24:11.459082715] [10643] DEBUG IPU3Awb awb.cpp:273 Gain found for
> > red: 1.16864 and for blue: 1.14863
> > [0:24:11.459325998] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:179 Queuing Exposure to 269 at index 194
> > [0:24:11.459562485] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:179 Queuing Analogue Gain to 477 at index 194
> > [0:24:11.459815347] [10629] DEBUG Request request.cpp:291
> > Request(129:C:0/1:140736750229136)
> > [0:24:11.460390126] [10629] DEBUG HAL camera_device.cpp:1117
> > '\_SB_.PCI0.I2C2.CAM0': Request 140736750229136 completed with 1 streams
> > [0:24:11.461855854] [10635] DEBUG Request request.cpp:94 Created request
> > - cookie: 140736750230064
> > [0:24:11.461939858] [10635] DEBUG HAL camera_device.cpp:941
> > '\_SB_.PCI0.I2C2.CAM0': Queueing request 140736750230064 with 1 streams
> > [0:24:11.462057435] [10635] DEBUG Buffer framebuffer.cpp:249 Buffer is
> > not contiguous
> > [0:24:11.462098906] [10635] DEBUG HAL camera_device.cpp:980
> > '\_SB_.PCI0.I2C2.CAM0': 0 - (4160x3104)[0x00000023] -> (4160x3104)[NV12]
> > (direct)
> > [0:24:11.463164722] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:237 frame 194 started
> > [0:24:11.463730946] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:272 Setting Analogue Gain to 477 at index 193
> > [0:24:11.464033686] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:272 Setting Exposure to 269 at index 194
> > [0:24:11.464329869] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video0[37:cap]: Queueing buffer 0
> > [0:24:11.495739092] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:237 frame 195 started
> > [0:24:11.496489311] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:272 Setting Analogue Gain to 477 at index 194
> > [0:24:11.496737385] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:285 Queue is empty, auto queue no-op.
> > [0:24:11.497044311] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video0[37:cap]: Dequeuing buffer 3
> > [0:24:11.497335155] [10643] DEBUG IPU3Awb awb.cpp:331 Color temperature
> > estimated: 6658
> > [0:24:11.497528845] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video6[25:cap]: Queueing buffer 2
> > [0:24:11.503589322] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video5[27:out]: Queueing buffer 3
> > [0:24:11.504027344] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video8[28:cap]: Queueing buffer 3
> > [0:24:11.504287330] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video4[24:out]: Queueing buffer 3
> > [0:24:11.504712501] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video4[24:out]: Dequeuing buffer 2
> > [0:24:11.505005096] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video6[25:cap]: Dequeuing buffer 1
> > [0:24:11.505260331] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video5[27:out]: Dequeuing buffer 3
> > [0:24:11.505506837] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video8[28:cap]: Dequeuing buffer 2
> > [0:24:11.505940926] [10643] DEBUG IPU3Awb awb.cpp:270 Valid zones: 186
> > [0:24:11.505976974] [10643] DEBUG IPU3Awb awb.cpp:224 Grey world AWB
> > [0:24:11.506057427] [10643] DEBUG IPU3Awb awb.cpp:273 Gain found for
> > red: 1.16797 and for blue: 1.14978
> > [0:24:11.506297848] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:179 Queuing Exposure to 269 at index 196
> > [0:24:11.506547021] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:179 Queuing Analogue Gain to 477 at index 196
> > [0:24:11.506796456] [10629] DEBUG Request request.cpp:291
> > Request(130:C:0/1:140736750225984)
> > [0:24:11.507374522] [10629] DEBUG HAL camera_device.cpp:1117
> > '\_SB_.PCI0.I2C2.CAM0': Request 140736750225984 completed with 1 streams
> > [0:24:11.509426987] [10635] DEBUG Request request.cpp:94 Created request
> > - cookie: 140736750227664
> > [0:24:11.509507039] [10635] DEBUG HAL camera_device.cpp:941
> > '\_SB_.PCI0.I2C2.CAM0': Queueing request 140736750227664 with 1 streams
> > [0:24:11.509630706] [10635] DEBUG Buffer framebuffer.cpp:249 Buffer is
> > not contiguous
> > [0:24:11.509675200] [10635] DEBUG HAL camera_device.cpp:980
> > '\_SB_.PCI0.I2C2.CAM0': 0 - (4160x3104)[0x00000023] -> (4160x3104)[NV12]
> > (direct)
> > [0:24:11.511309605] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1582
> > /dev/video0[37:cap]: Queueing buffer 1
> > [0:24:11.528984601] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:237 frame 196 started
> > [0:24:11.529446048] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:272 Setting Exposure to 269 at index 196
> > [0:24:11.548431632] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video4[24:out]: Dequeuing buffer 3
> > [0:24:11.548993830] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video6[25:cap]: Dequeuing buffer 2
> > [0:24:11.549320802] [10629] DEBUG V4L2 v4l2_videodevice.cpp:1650
> > /dev/video8[28:cap]: Dequeuing buffer 3
> > [0:24:11.549807736] [10643] DEBUG IPU3Awb awb.cpp:270 Valid zones: 186
> > [0:24:11.549846777] [10643] DEBUG IPU3Awb awb.cpp:224 Grey world AWB
> > [0:24:11.549927350] [10643] DEBUG IPU3Awb awb.cpp:273 Gain found for
> > red: 1.16841 and for blue: 1.14912
> > [0:24:11.550170924] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:179 Queuing Exposure to 269 at index 197
> > [0:24:11.550405629] [10629] DEBUG DelayedControls
> > delayed_controls.cpp:179 Queuing Analogue Gain to 477 at index 197
> > [0:24:11.550646460] [10629] DEBUG Request request.cpp:291
> > Request(131:C:0/1:140736750235824)
> > [0:24:11.551245104] [10629] DEBUG HAL camera_device.cpp:1117
> > '\_SB_.PCI0.I2C2.CAM0': Request 140736750235824 completed with 2 streams
> > [0:24:11.562307680] [10629] DEBUG EXIF exif.cpp:522 Created EXIF
> > instance (536 bytes)
> > [0:24:11.634800113] [10629] DEBUG JPEG encoder_libjpeg.cpp:220 JPEG
> > Encode Starting:4160x3104
> > 
> > Thread 6 "CameraModuleThr" received signal SIGSEGV, Segmentation fault.
> > [Switching to Thread 0x7fffe7fff640 (LWP 10629)]
> > 0x00007ffff597ead5 in
> > EncoderLibJpeg::compressNV(libcamera::Span<unsigned char const,
> > 18446744073709551615ul>) () from /usr/lib64/camera_hal/libcamera-hal.so
> > (gdb) bt
> > #0  0x00007ffff597ead5 in
> > EncoderLibJpeg::compressNV(libcamera::Span<unsigned char const,
> > 18446744073709551615ul>) () from /usr/lib64/camera_hal/libcamera-hal.so
> > #1  0x00007ffff597eda0 in
> > EncoderLibJpeg::encode(libcamera::Span<unsigned char const,
> > 18446744073709551615ul>, libcamera::Span<unsigned char,
> > 18446744073709551615ul>, libcamera::Span<unsigned char const,
> > 18446744073709551615ul>, unsigned int) () from
> > /usr/lib64/camera_hal/libcamera-hal.so
> > #2  0x00007ffff597ec53 in EncoderLibJpeg::encode(libcamera::FrameBuffer
> > const&, libcamera::Span<unsigned char, 18446744073709551615ul>,
> 
> 18446744073709551615ul is -1, so we've certainly missed
> capturing/preventing an error code from getting assigned to the span at
> some point, where it then got stored as an unsigned long.

This it the template argument, and -1 indicates a dynamic extent, as
opposed to Span<> instances that have a static extent.

> Does this happen repeatably? or only on some specific event?

-- 
Regards,

Laurent Pinchart