IPC and IPA errors on RPi 5 Bookworm

[fbridge8]

Hello everybody.

I'm having issues with libcamera, somewhat similar to these other issues:

#254 - Even the sensor is the same VD56G3, but I'm not using calibration files.
#115 - This didn't have a resolution, but I have installed libgnutls28-dev (I've followed the exact steps in the README to build, but same issue happen with libcamera's system package).

I went through some extensive debug in this other issue on camera_ros christianrauch/camera_ros#115

Basically this is what's happening (more detailed logs below).

[10:02:34.005492925] [181325] ERROR IPCPipe ipc_pipe_unixsocket.cpp:134 Call timeout!
[10:02:34.005523463] [181325] ERROR IPCPipe ipc_pipe_unixsocket.cpp:66 Failed to call sync
[10:02:34.005531333] [181325] ERROR IPAProxy raspberrypi_ipa_proxy.cpp:261 Failed to call start
[10:02:34.009190798] [181325] ERROR IPCUnixSocket ipc_unixsocket.cpp:192 Failed to send: Connection refused
[10:02:34.009221799] [181325] ERROR IPCPipe ipc_pipe_unixsocket.cpp:66 Failed to call sync
[10:02:34.009228836] [181325] ERROR IPAProxy raspberrypi_ipa_proxy.cpp:432 Failed to call mapBuffers
[10:02:34.067543539] [181325] ERROR IPCUnixSocket ipc_unixsocket.cpp:192 Failed to send: Transport endpoint is not connected
[10:02:34.067573243] [181325] ERROR IPCPipe ipc_pipe_unixsocket.cpp:80 Failed to call async
[10:02:34.067580317] [181325] ERROR IPAProxy raspberrypi_ipa_proxy.cpp:508 Failed to call prepareIsp

pi@raspberrypi:~ $ lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 12 (bookworm)
Release:        12
Codename:       bookworm

pi@raspberrypi:~ $ uname -a
Linux raspberrypi 6.12.20+rpt-rpi-2712 #1 SMP PREEMPT Debian 1:6.12.20-1+rpt1~bpo12+1 (2025-03-19) aarch64 GNU/Linux

(expand) LIBCAMERA_LOG_LEVELS=*:DEBUG when running the ROS2 node

pi@raspberrypi:~ $ LIBCAMERA_LOG_LEVELS=*:DEBUG ros2 run --prefix 'gdb -ex run --args' camera_ros camera_node --ros-args --log-level camera:=debug -p camera:=1 -p width:=640 -p height:=480GNU gdb (Debian 13.1-3) 13.1
Copyright (C) 2023 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "aarch64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /home/pi/ros2_jazzy/install/camera_ros/lib/camera_ros/camera_node...
(No debugging symbols found in /home/pi/ros2_jazzy/install/camera_ros/lib/camera_ros/camera_node)
Starting program: /home/pi/ros2_jazzy/install/camera_ros/lib/camera_ros/camera_node --ros-args --log-level camera:=debug -p camera:=1 -p width:=640 -p height:=480
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/aarch64-linux-gnu/libthread_db.so.1".
[New Thread 0x7ffff614a040 (LWP 181242)]
[New Thread 0x7ffff593a040 (LWP 181243)]
[New Thread 0x7fffefb7e040 (LWP 181244)]
[New Thread 0x7fffef36e040 (LWP 181245)]
[New Thread 0x7fffde4ae040 (LWP 181246)]
[New Thread 0x7fffdbc9e040 (LWP 181247)]
[New Thread 0x7fffd948e040 (LWP 181248)]
[New Thread 0x7fffd6c7e040 (LWP 181249)]
[New Thread 0x7fffd63e6040 (LWP 181250)]
[New Thread 0x7fffd5bd6040 (LWP 181251)]
[New Thread 0x7fffd53c6040 (LWP 181252)]
[New Thread 0x7fffd4bb6040 (LWP 181253)]
[New Thread 0x7fffd43a6040 (LWP 181254)]
[New Thread 0x7fffd3ad6040 (LWP 181255)]
[New Thread 0x7fffd325e040 (LWP 181256)]
[New Thread 0x7fffd2a4e040 (LWP 181257)]
[New Thread 0x7fffd223e040 (LWP 181258)]
[9:49:27.504851011] [181240] DEBUG IPAModule ipa_module.cpp:333 ipa_rpi_pisp.so: IPA module /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_pisp.so is signed
[9:49:27.504922307] [181240] DEBUG IPAManager ipa_manager.cpp:235 Loaded IPA module '/usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_pisp.so'
[9:49:27.505008697] [181240] DEBUG IPAModule ipa_module.cpp:333 ipa_rpi_vc4.so: IPA module /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_vc4.so is signed
[9:49:27.505038308] [181240] DEBUG IPAManager ipa_manager.cpp:235 Loaded IPA module '/usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_vc4.so'
[9:49:27.583320371] [181240]  INFO Camera camera_manager.cpp:327 libcamera v0.4.0+53-29156679
[New Thread 0x7fffd130e040 (LWP 181259)]
[9:49:27.583667539] [181259] DEBUG Camera camera_manager.cpp:73 Starting camera manager
[9:49:27.589859882] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:230 New media device "rp1-cfe" created from /dev/media1
[9:49:27.589955512] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:96 Defer media device /dev/media1 due to 10 missing dependencies
[9:49:27.590703831] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:322 All dependencies for media device /dev/media1 found
[9:49:27.590720831] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:258 Added device /dev/media1: rp1-cfe
[9:49:27.590798368] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:230 New media device "rp1-cfe" created from /dev/media2
[9:49:27.590880850] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:96 Defer media device /dev/media2 due to 10 missing dependencies
[9:49:27.591631353] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:322 All dependencies for media device /dev/media2 found
[9:49:27.591648279] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:258 Added device /dev/media2: rp1-cfe
[9:49:27.591708983] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:230 New media device "rpi-hevc-dec" created from /dev/media4
[9:49:27.591726335] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:96 Defer media device /dev/media4 due to 1 missing dependencies
[9:49:27.591819484] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:322 All dependencies for media device /dev/media4 found
[9:49:27.591834151] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:258 Added device /dev/media4: rpi-hevc-dec
[9:49:27.591903058] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:230 New media device "pispbe" created from /dev/media0
[9:49:27.591918670] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:96 Defer media device /dev/media0 due to 8 missing dependencies
[9:49:27.591986688] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:230 New media device "pispbe" created from /dev/media3
[9:49:27.592009874] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:96 Defer media device /dev/media3 due to 8 missing dependencies
[9:49:27.592584895] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:322 All dependencies for media device /dev/media0 found
[9:49:27.592601617] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:258 Added device /dev/media0: pispbe
[9:49:27.593169490] [181259] DEBUG DeviceEnumerator device_enumerator_udev.cpp:322 All dependencies for media device /dev/media3 found
[9:49:27.593184175] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:258 Added device /dev/media3: pispbe
[9:49:27.593440251] [181259] DEBUG Camera camera_manager.cpp:140 Found registered pipeline handler 'rpi/vc4'
[9:49:27.593468121] [181259] DEBUG RPI vc4.cpp:189 Unable to acquire a Unicam instance
[9:49:27.593480343] [181259] DEBUG RPI vc4.cpp:189 Unable to acquire a Unicam instance
[9:49:27.593491769] [181259] DEBUG Camera camera_manager.cpp:140 Found registered pipeline handler 'rpi/pisp'
[9:49:27.593507807] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:318 Successful match for media device "rp1-cfe"
[9:49:27.593534603] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:318 Successful match for media device "pispbe"
[9:49:27.593620622] [181259] DEBUG ClockRec clock_recovery.cpp:69 configure 100 2000 10 50000
[9:49:27.593640289] [181259] DEBUG ClockRec clock_recovery.cpp:83 reset
[9:49:27.593780493] [181259]  INFO RPI pisp.cpp:720 libpisp version v1.1.0 e7974a156008 27-01-2025 (21:50:51)
[9:49:27.594445181] [181259] DEBUG CameraSensor camera_sensor_raw.cpp:210 vd56g3 10-0010: unsupported number of sinks (0) or sources (1)
[9:49:27.594489533] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Exposure (0x00980911)
[9:49:27.594520274] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Horizontal Flip (0x00980914)
[9:49:27.594537552] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Vertical Flip (0x00980915)
[9:49:27.594554163] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Temperature in celsius (0x00981920)
[9:49:27.594570756] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: AE - Light level target (%) (0x00981921)
[9:49:27.594587719] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: AE - Convg. step proportion (0x00981922)
[9:49:27.594604089] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: AE - Convg. leak proportion (0x00981923)
[9:49:27.594620589] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Dark Calibration Pedestal (0x00981924)
[9:49:27.594637312] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Auto Exposure (0x009a0901)
[9:49:27.594659404] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Auto Exposure, Bias (0x009a0913)
[9:49:27.594686219] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: 3A Lock (0x009a091b)
[9:49:27.594702405] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Camera Orientation (0x009a0922)
[9:49:27.594721794] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Camera Sensor Rotation (0x009a0923)
[9:49:27.594738275] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Vertical Blanking (0x009e0901)
[9:49:27.594755071] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Horizontal Blanking (0x009e0902)
[9:49:27.594770775] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Analogue Gain (0x009e0903)
[9:49:27.594787442] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Link Frequency (0x009f0901)
[9:49:27.594804720] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Pixel Rate (0x009f0902)
[9:49:27.594820275] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Test Pattern (0x009f0903)
[9:49:27.594841035] [181259] DEBUG V4L2 v4l2_device.cpp:699 'vd56g3 10-0010': Control: Digital Gain (0x009f0905)
[9:49:27.595904466] [181259]  WARN CameraSensorProperties camera_sensor_properties.cpp:473 No static properties available for 'vd56g3'
[9:49:27.595925614] [181259]  WARN CameraSensorProperties camera_sensor_properties.cpp:475 Please consider updating the camera sensor properties database
[9:49:27.595945947] [181259] DEBUG CameraSensor camera_sensor.cpp:468 Entity 'vd56g3 10-0010' matched by CameraSensorLegacy
[9:49:27.596769525] [181259] DEBUG IPAManager ipa_manager.cpp:306 IPA module /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_pisp.so signature is not valid
[9:49:27.596816192] [181259] DEBUG IPAProxy raspberrypi_ipa_proxy.cpp:45 initializing raspberrypi proxy: loading IPA from /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_pisp.so
[Thread 0x7fffd948e040 (LWP 181248) exited]
[Thread 0x7fffdbc9e040 (LWP 181247) exited]
[Thread 0x7fffde4ae040 (LWP 181246) exited]
[Detaching after fork from child process 181260]
[9:49:27.598840461] [181259] DEBUG Timer timer.cpp:93 Starting timer 0x7fffd130bc60: deadline 9:49:29.598829201
[9:49:27.598940868] [181259] DEBUG Event event_dispatcher_poll.cpp:215 next timer 0x7fffd130bc60 expires in 1.999891758
[9:49:27.617833418] [181259]  WARN CameraSensor camera_sensor_legacy.cpp:501 'vd56g3 10-0010': No sensor delays found in static properties. Assuming unverified defaults.
[9:49:27.617878011] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 2 and priority write flag 1 for Vertical Blanking
[9:49:27.617893678] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 2 and priority write flag 0 for Horizontal Blanking
[9:49:27.617907530] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 2 and priority write flag 0 for Exposure
[9:49:27.617920011] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 1 and priority write flag 0 for Analogue Gain
[9:49:27.618045808] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video12[38:cap]: Opened device platform:1f00110000.csi: rp1-cfe: rp1-cfe
[9:49:27.618090105] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video15[39:out]: Opened device platform:1f00110000.csi: rp1-cfe: rp1-cfe
[9:49:27.618114827] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video14[40:cap]: Opened device platform:1f00110000.csi: rp1-cfe: rp1-cfe
[9:49:27.618139605] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video20[41:out]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.618195272] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video23[42:cap]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.618242550] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video24[43:cap]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.618288457] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video27[44:out]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.618310809] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video21[45:out]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.618354513] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video25[46:cap]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.618398291] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video22[47:out]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.618445291] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video26[48:cap]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.618492069] [181259]  INFO RPI pisp.cpp:1179 Registered camera /base/axi/pcie@1000120000/rp1/i2c@88000/fox@10 to CFE device /dev/media1 and ISP device /dev/media0 using PiSP variant BCM2712_C0
[9:49:27.618514662] [181259] DEBUG Camera camera_manager.cpp:161 Pipeline handler "rpi/pisp" matched
[9:49:27.618534681] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:318 Successful match for media device "rp1-cfe"
[9:49:27.618556162] [181259] DEBUG DeviceEnumerator device_enumerator.cpp:318 Successful match for media device "pispbe"
[9:49:27.618580033] [181259] DEBUG ClockRec clock_recovery.cpp:69 configure 100 2000 10 50000
[9:49:27.618592996] [181259] DEBUG ClockRec clock_recovery.cpp:83 reset
[9:49:27.618612218] [181259]  INFO RPI pisp.cpp:720 libpisp version v1.1.0 e7974a156008 27-01-2025 (21:50:51)
[9:49:27.619072128] [181259] DEBUG CameraSensor camera_sensor_raw.cpp:210 imx219 11-0010: unsupported number of sinks (0) or sources (1)
[9:49:27.619108572] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Exposure (0x00980911)
[9:49:27.619133239] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Horizontal Flip (0x00980914)
[9:49:27.619151313] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Vertical Flip (0x00980915)
[9:49:27.619166961] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Camera Orientation (0x009a0922)
[9:49:27.619189073] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Camera Sensor Rotation (0x009a0923)
[9:49:27.619205054] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Vertical Blanking (0x009e0901)
[9:49:27.619220387] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Horizontal Blanking (0x009e0902)
[9:49:27.619235906] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Analogue Gain (0x009e0903)
[9:49:27.619251202] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Red Pixel Value (0x009e0904)
[9:49:27.619266388] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Green (Red) Pixel Value (0x009e0905)
[9:49:27.619282073] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Blue Pixel Value (0x009e0906)
[9:49:27.619297629] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Green (Blue) Pixel Value (0x009e0907)
[9:49:27.619315888] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Link Frequency (0x009f0901)
[9:49:27.619333258] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Pixel Rate (0x009f0902)
[9:49:27.619350036] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Test Pattern (0x009f0903)
[9:49:27.619370110] [181259] DEBUG V4L2 v4l2_device.cpp:699 'imx219 11-0010': Control: Digital Gain (0x009f0905)
[9:49:27.620269726] [181259] DEBUG CameraSensor camera_sensor_legacy.cpp:1023 'imx219 11-0010': Apply test pattern mode 0
[9:49:27.620299689] [181259] DEBUG CameraSensor camera_sensor.cpp:468 Entity 'imx219 11-0010' matched by CameraSensorLegacy
[9:49:27.621002933] [181259] DEBUG IPAManager ipa_manager.cpp:306 IPA module /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_pisp.so signature is not valid
[9:49:27.621046137] [181259] DEBUG IPAProxy raspberrypi_ipa_proxy.cpp:45 initializing raspberrypi proxy: loading IPA from /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_pisp.so
[Detaching after fork from child process 181265]
[9:49:27.622955664] [181259] DEBUG Timer timer.cpp:93 Starting timer 0x7fffd130bc60: deadline 9:49:29.622946719
[9:49:27.623046053] [181259] DEBUG Event event_dispatcher_poll.cpp:215 next timer 0x7fffd130bc60 expires in 1.999902814
[9:49:27.657581286] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 2 and priority write flag 1 for Vertical Blanking
[9:49:27.657623175] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 2 and priority write flag 0 for Horizontal Blanking
[9:49:27.657637175] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 2 and priority write flag 0 for Exposure
[9:49:27.657652619] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 1 and priority write flag 0 for Analogue Gain
[9:49:27.657796176] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video4[57:cap]: Opened device platform:1f00128000.csi: rp1-cfe: rp1-cfe
[9:49:27.657842602] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video7[58:out]: Opened device platform:1f00128000.csi: rp1-cfe: rp1-cfe
[9:49:27.657867602] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video6[59:cap]: Opened device platform:1f00128000.csi: rp1-cfe: rp1-cfe
[9:49:27.657892417] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video28[60:out]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.657949306] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video31[61:cap]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.657996417] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video32[62:cap]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.658041047] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video35[63:out]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.676024426] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video29[64:out]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.676079871] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video33[65:cap]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.676125426] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video30[66:out]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.676171149] [181259] DEBUG V4L2 v4l2_videodevice.cpp:631 /dev/video34[67:cap]: Opened device platform:1000880000.pisp_be: pispbe: pispbe
[9:49:27.676218557] [181259]  INFO RPI pisp.cpp:1179 Registered camera /base/axi/pcie@1000120000/rp1/i2c@80000/imx219@10 to CFE device /dev/media2 and ISP device /dev/media3 using PiSP variant BCM2712_C0
[9:49:27.676244186] [181259] DEBUG Camera camera_manager.cpp:161 Pipeline handler "rpi/pisp" matched
[9:49:27.676263557] [181259] DEBUG RPI pisp.cpp:890 Unable to acquire a CFE instance
[9:49:27.676275723] [181259] DEBUG Camera camera_manager.cpp:140 Found registered pipeline handler 'uvcvideo'
[DEBUG] [1745568025.557917742] [camera]: found camera by id: 1
[9:49:27.676862319] [181240] DEBUG Camera camera.cpp:1137 streams configuration: (0) 800x600-XRGB8888
[DEBUG] [1745568025.558384633] [camera]: default Viewfinder stream configuration: "800x600-XRGB8888"
[DEBUG] [1745568025.558557059] [camera]: 
>> stream formats:
   - R8 (32x32 - 3280x2464)
   - R16 (32x32 - 3280x2464)
   - MONO_PISP_COMP1 (32x32 - 3280x2464)
   - SGRBG10 (32x32 - 3280x2464)
   - SGBRG10 (32x32 - 3280x2464)
   - SBGGR10 (32x32 - 3280x2464)
   - SRGGB10 (32x32 - 3280x2464)
   - NV21 (32x32 - 3280x2464)
   - SBGGR8 (32x32 - 3280x2464)
   - SGRBG12 (32x32 - 3280x2464)
   - SGBRG12 (32x32 - 3280x2464)
   - SBGGR12 (32x32 - 3280x2464)
   - SRGGB12 (32x32 - 3280x2464)
   - YUV420 (32x32 - 3280x2464)
   - NV12 (32x32 - 3280x2464)
   - YVU420 (32x32 - 3280x2464)
   - SBGGR16 (32x32 - 3280x2464)
   - BGGR_PISP_COMP1 (32x32 - 3280x2464)
   - SGRBG14 (32x32 - 3280x2464)
   - SGBRG14 (32x32 - 3280x2464)
   - SBGGR14 (32x32 - 3280x2464)
   - SRGGB14 (32x32 - 3280x2464)
   - XBGR8888 (32x32 - 3280x2464)
   - BGR888 (32x32 - 3280x2464)
   - RGB888 (32x32 - 3280x2464)
   - XRGB8888 (32x32 - 3280x2464)
   - YUV444 (32x32 - 3280x2464)
   - YVU444 (32x32 - 3280x2464)
   - SGBRG16 (32x32 - 3280x2464)
   - GBRG_PISP_COMP1 (32x32 - 3280x2464)
   - SGRBG16 (32x32 - 3280x2464)
   - GRBG_PISP_COMP1 (32x32 - 3280x2464)
   - YUV422 (32x32 - 3280x2464)
   - YVU422 (32x32 - 3280x2464)
   - SRGGB16 (32x32 - 3280x2464)
   - RGGB_PISP_COMP1 (32x32 - 3280x2464)
   - BGR161616 (32x32 - 3280x2464)
   - RGB161616 (32x32 - 3280x2464)
   - SRGGB8 (32x32 - 3280x2464)
   - SGRBG8 (32x32 - 3280x2464)
   - SGBRG8 (32x32 - 3280x2464)
   - YVYU (32x32 - 3280x2464)
   - YUYV (32x32 - 3280x2464)
   - VYUY (32x32 - 3280x2464)
   - UYVY (32x32 - 3280x2464)
[INFO] [1745568025.558913431] [camera]: 
>> stream formats:
   - R8 (32x32 - 3280x2464)
   - R16 (32x32 - 3280x2464)
   - MONO_PISP_COMP1 (32x32 - 3280x2464)
   - NV21 (32x32 - 3280x2464)
   - SBGGR8 (32x32 - 3280x2464)
   - SBGGR16 (32x32 - 3280x2464)
   - BGGR_PISP_COMP1 (32x32 - 3280x2464)
   - XBGR8888 (32x32 - 3280x2464)
   - BGR888 (32x32 - 3280x2464)
   - RGB888 (32x32 - 3280x2464)
   - XRGB8888 (32x32 - 3280x2464)
   - SGBRG16 (32x32 - 3280x2464)
   - GBRG_PISP_COMP1 (32x32 - 3280x2464)
   - SGRBG16 (32x32 - 3280x2464)
   - GRBG_PISP_COMP1 (32x32 - 3280x2464)
   - SRGGB16 (32x32 - 3280x2464)
   - RGGB_PISP_COMP1 (32x32 - 3280x2464)
   - BGR161616 (32x32 - 3280x2464)
   - RGB161616 (32x32 - 3280x2464)
   - SRGGB8 (32x32 - 3280x2464)
   - SGRBG8 (32x32 - 3280x2464)
   - SGBRG8 (32x32 - 3280x2464)
   - YUYV (32x32 - 3280x2464)
   - UYVY (32x32 - 3280x2464)
[WARN] [1745568025.559053247] [camera]: no pixel format selected, auto-selecting: "XRGB8888"
[WARN] [1745568025.559092025] [camera]: set parameter 'format' to silence this warning
[INFO] [1745568025.559182099] [camera]: 
>> XRGB8888 format sizes:
   - 160x120
   - 240x160
   - 320x240
   - 400x240
   - 480x320
   - 640x360
   - 640x480
   - 720x480
   - 768x480
   - 854x480
   - 720x576
   - 800x600
   - 960x540
   - 1024x576
   - 960x640
   - 1024x600
   - 1024x768
   - 1280x720
   - 1152x864
   - 1280x800
   - 1360x768
   - 1366x768
   - 1440x900
   - 1280x1024
   - 1536x864
   - 1280x1080
   - 1600x900
   - 1400x1050
   - 1680x1050
   - 1600x1200
   - 1920x1080
   - 2048x1080
   - 1920x1200
   - 2160x1080
   - 2048x1152
   - 2560x1080
   - 2048x1536
   - 2560x1440
   - 2560x1600
   - 2960x1440
   - 2560x2048
   - 3200x1800
   - 3200x2048
   - 3200x2400
[9:49:27.677923379] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 640x480 fmt SRGGB10 Score: 1000 (best 1000)
[9:49:27.677967509] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 1640x1232 fmt SRGGB10 Score: 1444.49 (best 1000)
[9:49:27.677976472] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 1920x1080 fmt SRGGB10 Score: 1636.67 (best 1000)
[9:49:27.677983954] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 3280x2464 fmt SRGGB10 Score: 2162.49 (best 1000)
[9:49:27.677991898] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 640x480 fmt SRGGB8 Score: 2000 (best 1000)
[9:49:27.677999305] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 1640x1232 fmt SRGGB8 Score: 2444.49 (best 1000)
[9:49:27.678006528] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 1920x1080 fmt SRGGB8 Score: 2636.67 (best 1000)
[9:49:27.678014065] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 3280x2464 fmt SRGGB8 Score: 3162.49 (best 1000)
[9:49:27.678022028] [181240] DEBUG RPI pisp.cpp:1276 minSize: width 10 height 8
[9:49:27.678048528] [181240] DEBUG RPI pisp.cpp:1411 Swapping 32-bit for 24-bit format
[9:49:27.678054806] [181240] DEBUG RPI pisp.cpp:1320 For stream 640x480-BGR3 swDownscale is 1
[9:49:27.678061602] [181240] DEBUG RPI pipeline_base.cpp:286 Try color space sRGB
[9:49:27.678076417] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 640x480 fmt SRGGB10 Score: 1000 (best 1000)
[9:49:27.678086287] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 1640x1232 fmt SRGGB10 Score: 1444.49 (best 1000)
[9:49:27.678094602] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 1920x1080 fmt SRGGB10 Score: 1636.67 (best 1000)
[9:49:27.678102250] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 3280x2464 fmt SRGGB10 Score: 2162.49 (best 1000)
[9:49:27.678109639] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 640x480 fmt SRGGB8 Score: 2000 (best 1000)
[9:49:27.678116713] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 1640x1232 fmt SRGGB8 Score: 2444.49 (best 1000)
[9:49:27.678124176] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 1920x1080 fmt SRGGB8 Score: 2636.67 (best 1000)
[9:49:27.678131306] [181240] DEBUG RPI pipeline_base.cpp:974 Format: 3280x2464 fmt SRGGB8 Score: 3162.49 (best 1000)
[9:49:27.678138528] [181240] DEBUG RPI pisp.cpp:1276 minSize: width 10 height 8
[9:49:27.678144917] [181240] DEBUG RPI pisp.cpp:1411 Swapping 32-bit for 24-bit format
[9:49:27.678150288] [181240] DEBUG RPI pisp.cpp:1320 For stream 640x480-BGR3 swDownscale is 1
[9:49:27.678155862] [181240] DEBUG RPI pipeline_base.cpp:286 Try color space sRGB
[9:49:27.678166565] [181240]  INFO Camera camera.cpp:1202 configuring streams: (0) 640x480-XRGB8888
[9:49:27.678203862] [181259] DEBUG Timer timer.cpp:93 Starting timer 0x7fffd130c420: deadline 9:49:29.678202492
[9:49:27.678224825] [181259] DEBUG Event event_dispatcher_poll.cpp:215 next timer 0x7fffd130c420 expires in 1.999978408
[9:49:27.678329751] [181259]  INFO RPI pisp.cpp:1484 Sensor: /base/axi/pcie@1000120000/rp1/i2c@80000/imx219@10 - Selected sensor format: 640x480-SBGGR10_1X10 - Selected CFE format: 640x480-PC1B
[9:49:27.678350400] [181259] DEBUG RPI pisp.cpp:1411 Swapping 32-bit for 24-bit format
[9:49:27.678361585] [181259] DEBUG RPI pisp.cpp:1542 Setting ISP Output1 to 640x480-BGR3 (sw downscale 1)
[9:49:27.678375992] [181259] DEBUG RPI pisp.cpp:1548 After setFormat, stride 2560
[9:49:27.678386881] [181259] DEBUG RPI pisp.cpp:1558 Stream ISP Output1 has color space sRGB
[9:49:27.678398215] [181259] DEBUG RPI pisp.cpp:2161 Output 1 (0, 0)/640x480
[9:49:27.678422752] [181259] DEBUG MediaDevice media_device.cpp:826 /dev/media2[rp1-cfe]: 'csi2'[4] -> 'rp1-cfe-csi2_ch0'[0]: 0
[9:49:27.678438215] [181259] DEBUG MediaDevice media_device.cpp:826 /dev/media2[rp1-cfe]: 'csi2'[4] -> 'pisp-fe'[0]: 1
[9:49:27.678451382] [181259] DEBUG MediaDevice media_device.cpp:826 /dev/media2[rp1-cfe]: 'csi2'[5] -> 'rp1-cfe-embedded'[0]: 0
[9:49:27.678464567] [181259] DEBUG MediaDevice media_device.cpp:826 /dev/media2[rp1-cfe]: 'rp1-cfe-fe_config'[0] -> 'pisp-fe'[1]: 1
[9:49:27.678478345] [181259] DEBUG MediaDevice media_device.cpp:826 /dev/media2[rp1-cfe]: 'pisp-fe'[2] -> 'rp1-cfe-fe_image0'[0]: 1
[9:49:27.678491345] [181259] DEBUG MediaDevice media_device.cpp:826 /dev/media2[rp1-cfe]: 'pisp-fe'[3] -> 'rp1-cfe-fe_image1'[0]: 0
[9:49:27.678504678] [181259] DEBUG MediaDevice media_device.cpp:826 /dev/media2[rp1-cfe]: 'pisp-fe'[4] -> 'rp1-cfe-fe_stats'[0]: 1
[9:49:27.678600771] [181259] DEBUG Timer timer.cpp:93 Starting timer 0x7fffd130bf90: deadline 9:49:29.678599493
[9:49:27.678617827] [181259] DEBUG Event event_dispatcher_poll.cpp:215 next timer 0x7fffd130bf90 expires in 1.999982351
[INFO] [1745568025.560379642] [camera]: camera "/base/axi/pcie@1000120000/rp1/i2c@80000/imx219@10" configured with 640x480-XRGB8888 stream
[INFO] [1745568025.560852440] [camera]: using default calibration URL
[INFO] [1745568025.560929144] [camera]: camera calibration URL: file:///home/pi/.ros/camera_info/imx219__base_axi_pcie_1000120000_rp1_i2c_80000_imx219_10_640x480.yaml
[DEBUG] [1745568025.560960978] [camera]: reading camera calibration from /home/pi/.ros/camera_info/imx219__base_axi_pcie_1000120000_rp1_i2c_80000_imx219_10_640x480.yaml
[ERROR] [1745568025.561070071] [camera_calibration_parsers]: Unable to open camera calibration file [/home/pi/.ros/camera_info/imx219__base_axi_pcie_1000120000_rp1_i2c_80000_imx219_10_640x480.yaml]
[WARN] [1745568025.561142201] [camera]: Camera calibration file /home/pi/.ros/camera_info/imx219__base_axi_pcie_1000120000_rp1_i2c_80000_imx219_10_640x480.yaml not found
[WARN] [1745568025.561243646] [camera]: unknown control: NoiseReductionMode (10002)
[DEBUG] [1745568025.561389202] [camera]: declare 'Sharpness' (type: double)
[DEBUG] [1745568025.561694704] [camera]: declare 'StatsOutputEnable' (type: bool)
[DEBUG] [1745568025.561936890] [camera]: declare 'ScalerCrop' (type: integer_array)
[DEBUG] [1745568025.562135891] [camera]: declare 'Brightness' (type: double)
[WARN] [1745568025.562276910] [camera]: FrameDurationLimits: cannot set default scalar value '33333' on span control (extend: 2), default will be ignored
[DEBUG] [1745568025.562363762] [camera]: declare 'FrameDurationLimits' (type: integer_array)
[WARN] [1745568025.562515689] [camera]: unknown control: CnnEnableInputTensor (20007)
[DEBUG] [1745568025.562604115] [camera]: declare 'AeConstraintMode' (type: integer)
[DEBUG] [1745568025.562763708] [camera]: declare 'Saturation' (type: double)
[DEBUG] [1745568025.562913950] [camera]: declare 'ColourTemperature' (type: integer)
[DEBUG] [1745568025.563077247] [camera]: declare 'AwbMode' (type: integer)
[DEBUG] [1745568025.563231859] [camera]: declare 'ColourGains' (type: double_array)
[DEBUG] [1745568025.563376489] [camera]: declare 'AwbEnable' (type: bool)
[DEBUG] [1745568025.563528119] [camera]: declare 'HdrMode' (type: integer)
[DEBUG] [1745568025.563678027] [camera]: declare 'AeMeteringMode' (type: integer)
[DEBUG] [1745568025.563844658] [camera]: declare 'Contrast' (type: double)
[DEBUG] [1745568025.563999733] [camera]: declare 'ExposureValue' (type: double)
[WARN] [1745568025.564132511] [camera]: unknown control: SyncFrames (20014)
[DEBUG] [1745568025.564215900] [camera]: declare 'AnalogueGain' (type: double)
[DEBUG] [1745568025.564357179] [camera]: declare 'AeFlickerPeriod' (type: integer)
[DEBUG] [1745568025.564492957] [camera]: declare 'AeEnable' (type: bool)
[WARN] [1745568025.564621680] [camera]: unknown control: SyncMode (20011)
[DEBUG] [1745568025.564698625] [camera]: declare 'AeExposureMode' (type: integer)
[DEBUG] [1745568025.564842625] [camera]: declare 'AeFlickerMode' (type: integer)
[DEBUG] [1745568025.565000015] [camera]: declare 'ExposureTime' (type: integer)
[DEBUG] [1745568025.565142127] [camera]: resolve defaults: AeEnable and ExposureTime must not be enabled at the same time. 'ExposureTime' will be disabled.
[DEBUG] [1745568025.565657425] [camera]: setting integer parameter AeExposureMode to 0
[DEBUG] [1745568025.565703203] [camera]: setting bool parameter AeEnable to true
[DEBUG] [1745568025.565741241] [camera]: setting double parameter AnalogueGain to 1.000000
[DEBUG] [1745568025.565774056] [camera]: setting double parameter Contrast to 1.000000
[DEBUG] [1745568025.565807074] [camera]: setting double parameter Sharpness to 1.000000
[DEBUG] [1745568025.565842611] [camera]: setting integer parameter AeFlickerMode to 0
[DEBUG] [1745568025.565879130] [camera]: setting bool parameter StatsOutputEnable to false
[DEBUG] [1745568025.565934316] [camera]: setting integer_array parameter ScalerCrop to [1000, 752, 1280, 960]
[DEBUG] [1745568025.565973094] [camera]: setting double parameter ExposureValue to 0.000000
[DEBUG] [1745568025.566006742] [camera]: setting integer parameter HdrMode to 0
[DEBUG] [1745568025.566040946] [camera]: setting double parameter Brightness to 0.000000
[DEBUG] [1745568025.566075224] [camera]: setting integer parameter AeConstraintMode to 0
[DEBUG] [1745568025.566108816] [camera]: setting double parameter Saturation to 1.000000
[DEBUG] [1745568025.566142891] [camera]: setting integer parameter AwbMode to 0
[DEBUG] [1745568025.566180483] [camera]: setting integer parameter AeMeteringMode to 0
[9:49:27.685817656] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video32[62:cap]: 4 buffers requested.
[9:49:27.685871823] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:27.685892453] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:27.685908249] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:27.685923509] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:27.685941620] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video32[62:cap]: 0 buffers requested.
[9:49:27.686028768] [181240] DEBUG Request request.cpp:369 Created request - cookie: 0
[9:49:27.686108324] [181240] DEBUG Request request.cpp:369 Created request - cookie: 0
[9:49:27.686157954] [181240] DEBUG Request request.cpp:369 Created request - cookie: 0
[9:49:27.686217436] [181240] DEBUG Request request.cpp:369 Created request - cookie: 0
[New Thread 0x7fffd948e040 (LWP 181270)]
[New Thread 0x7fffdbc9e040 (LWP 181271)]
[New Thread 0x7fffde4ae040 (LWP 181272)]
[New Thread 0x7fffc3ffe040 (LWP 181273)]
[9:49:27.687061032] [181240] DEBUG Camera camera.cpp:1360 Starting capture
[9:49:27.687136829] [181259] DEBUG Timer timer.cpp:93 Starting timer 0x7fffd130c5a0: deadline 9:49:29.687134921
[9:49:27.687161348] [181259] DEBUG Event event_dispatcher_poll.cpp:215 next timer 0x7fffd130c5a0 expires in 1.999974314
[9:49:27.691819017] [181259] DEBUG Event event_dispatcher_poll.cpp:215 next timer 0x7fffd130c5a0 expires in 1.995318293
[9:49:29.689178076] [181259] ERROR IPCPipe ipc_pipe_unixsocket.cpp:134 Call timeout!
[9:49:29.689212557] [181259] ERROR IPCPipe ipc_pipe_unixsocket.cpp:66 Failed to call sync
[9:49:29.689223280] [181259] ERROR IPAProxy raspberrypi_ipa_proxy.cpp:261 Failed to call start
[9:49:29.689252335] [181259] DEBUG RPI pisp.cpp:1020 Preparing 4 buffers for stream CFE Image
[9:49:29.689741023] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video4[57:cap]: 4 buffers requested.
[9:49:29.689780190] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.689798653] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.689815449] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.689830931] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.689847245] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video4[57:cap]: 0 buffers requested.
[9:49:29.689921487] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video4[57:cap]: 32 buffers requested.
[9:49:29.689943061] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video4[57:cap]: Prepared to import 32 buffers
[9:49:29.689954302] [181259] DEBUG RPI pisp.cpp:1020 Preparing 12 buffers for stream CFE Config
[9:49:29.690580064] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video7[58:out]: 12 buffers requested.
[9:49:29.690602897] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690619638] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690636619] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690652268] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690667805] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690683286] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690699083] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690715157] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690731213] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690748064] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690763731] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690779361] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.690795472] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video7[58:out]: 0 buffers requested.
[9:49:29.690879028] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video7[58:out]: 32 buffers requested.
[9:49:29.690894806] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video7[58:out]: Prepared to import 32 buffers
[9:49:29.690905028] [181259] DEBUG RPI pisp.cpp:1020 Preparing 12 buffers for stream CFE Stats
[9:49:29.691579235] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video6[59:cap]: 12 buffers requested.
[9:49:29.691601791] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691617365] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691634420] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691649791] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691665124] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691680254] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691695606] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691710736] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691725662] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691740736] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691755625] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691770847] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.691787180] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video6[59:cap]: 0 buffers requested.
[9:49:29.691812643] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video6[59:cap]: 32 buffers requested.
[9:49:29.691824625] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video6[59:cap]: Prepared to import 32 buffers
[9:49:29.691835069] [181259] DEBUG RPI pisp.cpp:1020 Preparing 4 buffers for stream ISP Input
[9:49:29.691864162] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video28[60:out]: 32 buffers requested.
[9:49:29.691877144] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video28[60:out]: Prepared to import 32 buffers
[9:49:29.691887866] [181259] DEBUG RPI pisp.cpp:1020 Preparing 2 buffers for stream ISP Config
[9:49:29.692051052] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video35[63:out]: 2 buffers requested.
[9:49:29.692076941] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.692105811] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.692129626] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video35[63:out]: 0 buffers requested.
[9:49:29.692182645] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video35[63:out]: 32 buffers requested.
[9:49:29.692206886] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video35[63:out]: Prepared to import 32 buffers
[9:49:29.692229219] [181259] DEBUG RPI pisp.cpp:1020 Preparing 2 buffers for stream ISP TDN Input
[9:49:29.692261720] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video29[64:out]: 32 buffers requested.
[9:49:29.692283646] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video29[64:out]: Prepared to import 32 buffers
[9:49:29.692299849] [181259] DEBUG RPI pisp.cpp:1020 Preparing 2 buffers for stream ISP TDN Output
[9:49:29.692552999] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video33[65:cap]: 2 buffers requested.
[9:49:29.692576869] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.692592925] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.692607721] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video33[65:cap]: 0 buffers requested.
[9:49:29.692634258] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video33[65:cap]: 32 buffers requested.
[9:49:29.692647962] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video33[65:cap]: Prepared to import 32 buffers
[9:49:29.692658277] [181259] DEBUG RPI pisp.cpp:1020 Preparing 2 buffers for stream ISP Stitch Input
[9:49:29.692685240] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video30[66:out]: 32 buffers requested.
[9:49:29.692698018] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video30[66:out]: Prepared to import 32 buffers
[9:49:29.692708203] [181259] DEBUG RPI pisp.cpp:1020 Preparing 2 buffers for stream ISP Stitch Output
[9:49:29.692951000] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video34[67:cap]: 2 buffers requested.
[9:49:29.692971667] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.692987223] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.693002204] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video34[67:cap]: 0 buffers requested.
[9:49:29.693029001] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video34[67:cap]: 32 buffers requested.
[9:49:29.693042612] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video34[67:cap]: Prepared to import 32 buffers
[9:49:29.693053242] [181259] DEBUG RPI pisp.cpp:1020 Preparing 2 buffers for stream ISP Output1
[9:49:29.693540725] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video32[62:cap]: 2 buffers requested.
[9:49:29.693561429] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.693577392] [181259] DEBUG Buffer framebuffer.cpp:351 Buffer is contiguous
[9:49:29.693591781] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video32[62:cap]: 0 buffers requested.
[9:49:29.693655522] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1334 /dev/video32[62:cap]: 32 buffers requested.
[9:49:29.693669578] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1601 /dev/video32[62:cap]: Prepared to import 32 buffers
[9:49:29.693826542] [181259] ERROR IPCUnixSocket ipc_unixsocket.cpp:192 Failed to send: Connection refused
[9:49:29.693845597] [181259] ERROR IPCPipe ipc_pipe_unixsocket.cpp:66 Failed to call sync
[9:49:29.693854894] [181259] ERROR IPAProxy raspberrypi_ipa_proxy.cpp:432 Failed to call mapBuffers
[9:49:29.693869005] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 1 for CFE Image
[9:49:29.693883560] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video4[57:cap]: Queueing buffer 0
[9:49:29.693961431] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 2 for CFE Image
[9:49:29.693976764] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video4[57:cap]: Queueing buffer 1
[9:49:29.694039931] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 3 for CFE Image
[9:49:29.694053709] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video4[57:cap]: Queueing buffer 2
[9:49:29.694117191] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 4 for CFE Image
[9:49:29.694129747] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video4[57:cap]: Queueing buffer 3
[9:49:29.694191951] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 1 for CFE Stats
[9:49:29.694205025] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 0
[9:49:29.694266284] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 2 for CFE Stats
[9:49:29.694279414] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 1
[9:49:29.694338136] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 3 for CFE Stats
[9:49:29.694350803] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 2
[9:49:29.694409729] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 4 for CFE Stats
[9:49:29.694421915] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 3
[9:49:29.694480674] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 5 for CFE Stats
[9:49:29.694492859] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 4
[9:49:29.694551545] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 6 for CFE Stats
[9:49:29.694563693] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 5
[9:49:29.694623027] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 7 for CFE Stats
[9:49:29.694635286] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 6
[9:49:29.694695416] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 8 for CFE Stats
[9:49:29.694707564] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 7
[9:49:29.694766713] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 9 for CFE Stats
[9:49:29.694779250] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 8
[9:49:29.694838880] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 10 for CFE Stats
[9:49:29.694851583] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 9
[9:49:29.694911121] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 11 for CFE Stats
[9:49:29.694923473] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 10
[9:49:29.694982602] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 12 for CFE Stats
[9:49:29.694995084] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video6[59:cap]: Queueing buffer 11
[9:49:29.695055343] [181259] DEBUG ClockRec clock_recovery.cpp:111 addSample
[9:49:29.695066603] [181259] DEBUG ClockRec clock_recovery.cpp:141 addSample 35369695065 1745568027576547
[9:49:29.695076640] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369695065 1745568027576547
[9:49:29.695152955] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 1 for CFE Config
[9:49:29.695169233] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video7[58:out]: Queueing buffer 0
[9:49:29.695240548] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 2 for CFE Config
[9:49:29.695260530] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video7[58:out]: Queueing buffer 1
[9:49:29.728119032] [181259] DEBUG RPI pipeline_base.cpp:748 queueRequestDevice: New request sequence: 0
[9:49:29.728144977] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 1 for ISP Output1
[9:49:29.728161329] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video32[62:cap]: Queueing buffer 0
[9:49:29.728256385] [181259] DEBUG RPI pipeline_base.cpp:748 queueRequestDevice: New request sequence: 1
[9:49:29.728271144] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 2 for ISP Output1
[9:49:29.728282978] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video32[62:cap]: Queueing buffer 1
[9:49:29.728363996] [181259] DEBUG RPI pipeline_base.cpp:748 queueRequestDevice: New request sequence: 2
[9:49:29.728378108] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 3 for ISP Output1
[9:49:29.728389385] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video32[62:cap]: Queueing buffer 2
[9:49:29.728468182] [181259] DEBUG RPI pipeline_base.cpp:748 queueRequestDevice: New request sequence: 3
[9:49:29.728483164] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 4 for ISP Output1
[9:49:29.728494275] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video32[62:cap]: Queueing buffer 3
[9:49:29.750122522] [181259] DEBUG RPI pipeline_base.cpp:1387 Frame start 0
[9:49:29.750155097] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:240 frame 0 started
[9:49:29.759231712] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video4[57:cap]: Dequeuing buffer 0
[9:49:29.759257879] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Image buffer dequeue, buffer id 1, timestamp: 35369750095000
[9:49:29.759283712] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Analogue Gain to 0 at index 0
[9:49:29.759304083] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Exposure to 1058 at index 0
[9:49:29.759324250] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Horizontal Blanking to 2808 at index 0
[9:49:29.759341750] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Vertical Blanking to 1283 at index 0
[9:49:29.759360898] [181259] DEBUG ClockRec clock_recovery.cpp:111 addSample
[9:49:29.759379435] [181259] DEBUG ClockRec clock_recovery.cpp:141 addSample 35369759378 1745568027640860
[9:49:29.759396694] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369759378 1745568027640860
[9:49:29.759413861] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369695065 1745568027576547
[9:49:29.759430972] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369759378 1745568027640860
[9:49:29.759447991] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369750095 1745568027631577
[9:49:29.759471047] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video7[58:out]: Dequeuing buffer 0
[9:49:29.759493232] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Config buffer dequeue, buffer id 1, timestamp: 35369750095000
[9:49:29.759512325] [181259] DEBUG RPI pipeline_base.cpp:1442 Returning buffer to stream CFE Config
[9:49:29.759532288] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 3 for CFE Config
[9:49:29.759552973] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video7[58:out]: Queueing buffer 2
[9:49:29.759634399] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video6[59:cap]: Dequeuing buffer 0
[9:49:29.759658548] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Stats buffer dequeue, buffer id 1, timestamp: 35369750095000
[9:49:29.759695825] [181259] DEBUG RPI pisp.cpp:2362 Signalling IPA processStats and prepareIsp: Bayer buffer id: 1 Stats buffer id: 1
[9:49:29.759759585] [181259] ERROR IPCUnixSocket ipc_unixsocket.cpp:192 Failed to send: Transport endpoint is not connected
[9:49:29.759786400] [181259] ERROR IPCPipe ipc_pipe_unixsocket.cpp:80 Failed to call async
[9:49:29.759805048] [181259] ERROR IPAProxy raspberrypi_ipa_proxy.cpp:508 Failed to call prepareIsp
[9:49:29.783437916] [181259] DEBUG RPI pipeline_base.cpp:1387 Frame start 1
[9:49:29.783461472] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:240 frame 1 started
[9:49:29.783478953] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:283 Queue is empty, auto queue no-op.
[9:49:29.792584847] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video4[57:cap]: Dequeuing buffer 1
[9:49:29.792610847] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Image buffer dequeue, buffer id 2, timestamp: 35369783417000
[9:49:29.792630292] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Analogue Gain to 0 at index 0
[9:49:29.792647995] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Exposure to 1058 at index 0
[9:49:29.792666347] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Horizontal Blanking to 2808 at index 0
[9:49:29.792683273] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Vertical Blanking to 1283 at index 0
[9:49:29.792701329] [181259] DEBUG ClockRec clock_recovery.cpp:111 addSample
[9:49:29.792718255] [181259] DEBUG ClockRec clock_recovery.cpp:141 addSample 35369792717 1745568027674199
[9:49:29.792735125] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369792717 1745568027674199
[9:49:29.792751070] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369759378 1745568027640860
[9:49:29.792767088] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369792717 1745568027674199
[9:49:29.792784237] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369783417 1745568027664899
[9:49:29.792805403] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video7[58:out]: Dequeuing buffer 1
[9:49:29.792827070] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Config buffer dequeue, buffer id 2, timestamp: 35369783417000
[9:49:29.792844348] [181259] DEBUG RPI pipeline_base.cpp:1442 Returning buffer to stream CFE Config
[9:49:29.792861996] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 4 for CFE Config
[9:49:29.792882515] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video7[58:out]: Queueing buffer 3
[9:49:29.792959941] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video6[59:cap]: Dequeuing buffer 1
[9:49:29.792982052] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Stats buffer dequeue, buffer id 2, timestamp: 35369783417000
[9:49:29.816758013] [181259] DEBUG RPI pipeline_base.cpp:1387 Frame start 2
[9:49:29.816779236] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:240 frame 2 started
[9:49:29.816794921] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:283 Queue is empty, auto queue no-op.
[9:49:29.825880870] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video4[57:cap]: Dequeuing buffer 2
[9:49:29.825901926] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Image buffer dequeue, buffer id 3, timestamp: 35369816745000
[9:49:29.825919741] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Analogue Gain to 0 at index 0
[9:49:29.825936148] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Exposure to 1058 at index 0
[9:49:29.825953537] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Horizontal Blanking to 2808 at index 0
[9:49:29.825969722] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Vertical Blanking to 1283 at index 0
[9:49:29.825986463] [181259] DEBUG ClockRec clock_recovery.cpp:111 addSample
[9:49:29.826001593] [181259] DEBUG ClockRec clock_recovery.cpp:141 addSample 35369826000 1745568027707482
[9:49:29.826016815] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369826000 1745568027707482
[9:49:29.826031926] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369792717 1745568027674199
[9:49:29.826046871] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369826000 1745568027707482
[9:49:29.826063982] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369816745 1745568027698227
[9:49:29.826082853] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video7[58:out]: Dequeuing buffer 2
[9:49:29.826102575] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Config buffer dequeue, buffer id 3, timestamp: 35369816745000
[9:49:29.826119019] [181259] DEBUG RPI pipeline_base.cpp:1442 Returning buffer to stream CFE Config
[9:49:29.826135445] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 5 for CFE Config
[9:49:29.826155279] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video7[58:out]: Queueing buffer 4
[9:49:29.826225983] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video6[59:cap]: Dequeuing buffer 2
[9:49:29.826247816] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Stats buffer dequeue, buffer id 3, timestamp: 35369816745000
[9:49:29.850083278] [181259] DEBUG RPI pipeline_base.cpp:1387 Frame start 3
[9:49:29.850102018] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:240 frame 3 started
[9:49:29.850117537] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:283 Queue is empty, auto queue no-op.
[9:49:29.859206116] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video4[57:cap]: Dequeuing buffer 3
[9:49:29.859228523] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Image buffer dequeue, buffer id 4, timestamp: 35369850072000
[9:49:29.859246357] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Analogue Gain to 0 at index 1
[9:49:29.859262672] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Exposure to 1058 at index 1
[9:49:29.859279079] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Horizontal Blanking to 2808 at index 1
[9:49:29.859295246] [181259] DEBUG RPiDelayedControls delayed_controls.cpp:220 Reading Vertical Blanking to 1283 at index 1
[9:49:29.859312394] [181259] DEBUG ClockRec clock_recovery.cpp:111 addSample
[9:49:29.859327820] [181259] DEBUG ClockRec clock_recovery.cpp:141 addSample 35369859326 1745568027740808
[9:49:29.859343209] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369859326 1745568027740808
[9:49:29.859358431] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369826000 1745568027707482
[9:49:29.859375098] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369859326 1745568027740808
[9:49:29.859391339] [181259] DEBUG ClockRec clock_recovery.cpp:225 getOutput 35369850072 1745568027731554
[9:49:29.859410376] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video7[58:out]: Dequeuing buffer 3
[9:49:29.859430450] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Config buffer dequeue, buffer id 4, timestamp: 35369850072000
[9:49:29.859446802] [181259] DEBUG RPI pipeline_base.cpp:1442 Returning buffer to stream CFE Config
[9:49:29.859463265] [181259] DEBUG RPISTREAM rpi_stream.cpp:271 Queuing buffer 6 for CFE Config
[9:49:29.859482339] [181259] DEBUG V4L2 v4l2_videodevice.cpp:2011 /dev/video7[58:out]: Queueing buffer 5
[9:49:29.859554006] [181259] DEBUG V4L2 v4l2_videodevice.cpp:1731 /dev/video6[59:cap]: Dequeuing buffer 3
[9:49:29.859575858] [181259] DEBUG RPI pisp.cpp:1712 Stream CFE Stats buffer dequeue, buffer id 4, timestamp: 35369850072000

There are some signature issues above, not sure if related.

DEBUG IPAManager ipa_manager.cpp:306 IPA module /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_pisp.so signature is not valid

Because they also appear in LIBCAMERA_LOG_LEVELS=*:DEBUG libcamera-hello -t 100 but it doesn't fail there.

libcamera_debug_logs.txt

Any help/direction is welcome.

Thanks!

[kbingham]

As with #254 (comment) - make sure you install all the dependencies - even though they are marked optional for IPA signing.

If the IPA is run externally - and crashes - currently you don't get any notification of what the crash is (which is really unhelpful).

There's some patches to get the errors for external IPAs reported in the libcamera logs - but they aren't merged/upstream yet.

So the easiest way to be able to see what went wrong is to be absolutely sure that the IPA is not isolated - which means install the dependencies - and make sure the line "DEBUG IPAManager ipa_manager.cpp:306 IPA module /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi_pisp.so signature is not valid" is not printed. That line means the IPA is going to be run in isolation (and you won't get the IPA logs).

[kbingham]

Except- I think I just read in your 'other' issues that you have installed an /external/ IPA package from ST.

"Only libcamera-ipa:arm64 0.4.0+rpt20250213+st20250401-1 comes from ST."

You will really have to check what ST are doing there if you're not compiling this yourself from source.

[naushir]

Indeed, you definately don't want to run in IPA isolated mode on the RPi platforms as there is no reason to. Do you use the Raspberry Pi provided libcamera/ipa library files? If so, you really should not be running into this as they will be signed correctly at build time before packaging.

[kbingham]

I've pinged ST on this directly in the libcamera IRC channel ...

[naushir]

@fbridge8 can you please raise this with ST directly? Unfortunately we don't have access to their source at present to debug any further.

[fbridge8]

Yes, getting the IPA package from https://www.st.com/en/embedded-software/stsw-img502.html

What confuses me is that running libcamera-hello also raises the same "signature is not valid" I get when running ROS, but doesn't crash, and produces images as if nothing had happened. How's that possible?

I'll raise this in the ST forum. Any direction or something I should mention to better steer them towards the issue?

[naushir]

Any direction or something I should mention to better steer them towards the issue?

I suggest mentioning that the IPA isolation (due to invalid signature) hides any error messages (for now) making debug difficult, and the best outcome would be to upstream code to support this sensor so we don't run in isolated mode.

[christianrauch]

What confuses me is that running libcamera-hello also raises the same "signature is not valid" I get when running ROS, but doesn't crash, and produces images as if nothing had happened. How's that possible?

In both cases, you are running an isolated IPA module. But for some reason, you only hit the timeout issue (Call timeout!) with the ROS node. I was able to reproduce this Call timeout! issue with the cam executable when not signing the modules and reported this as: https://bugs.libcamera.org/show_bug.cgi?id=191.

[kbingham]

"Call timeout!" is the same as saying "The IPA has crashed or failed to load".

Figuring that out - requires getting the logs from the IPA... hopefully - someone at ST can do this.

[mugnierb]

If you open an issue on ST forums please put a link here so we can follow along at ST ;)

[estevanmaito]

We've opened an issue on ST forum, here's a link for reference: https://community.st.com/t5/imaging-sensors/invalid-signature-error-in-ipa-module-for-vd56g3/m-p/796819

Many thanks to everybody involved.