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

Mon Sep 6 12:43:15 CEST 2021

On 06/09/2021 11:08, Umang Jain wrote:
> Hi Laurent
> 
> 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.

Does this happen repeatably? or only on some specific event?
--
Kieran