raspberrypi / rpicam-apps

BSD 2-Clause "Simplified" License
416 stars 227 forks source link

[BUG] Sink camera gives ERROR IPARPI cam_helper.cpp:225 Embedded data buffer parsing failed #614

Closed lindlou closed 9 months ago

lindlou commented 11 months ago

Describe the bug I am following the documentation to capture two synchronized videos with two Pis and two HQ cameras.

To prevent the sink camera from timing out before it receives sync signals (see this post) I added "camera_timeout_value_ms": 9000, to /usr/share/libcamera/pipeline/rpi/vc4/rpi_apps.yaml.

But now on the sink I get this error as soon as I start recording on the source (before the sink's timeout completes): ERROR IPARPI cam_helper.cpp:225 Embedded data buffer parsing failed

If I start the sink when the source is already recording there is no bug and it works just fine.

Bug reports bug_sink.txt bug_source.txt

Additional information I upgraded the system with sudo apt update and sudo apt upgrade this morning, installed rpicam-vid manually with sudo apt install rpicam-apps (even after the upgrade I only had libcamera-vid) and tried rebooting a few times.

naushir commented 11 months ago

Can you post the full error log please? The bug reports seem to have them missing. Also, do you get the same problem if you swap source and sink devices?

lindlou commented 11 months ago

Full error log $ rpicam-vid --frames 100 --nopreview -o sink.h264

[0:09:04.102392864] [2062]  INFO Camera camera_manager.cpp:284 libcamera v0.1.0+118-563cd78e
[0:09:04.156893530] [2065]  WARN RPiSdn sdn.cpp:39 Using legacy SDN tuning - please consider moving SDN inside rpi.denoise
[0:09:04.159493580] [2065]  INFO RPI vc4.cpp:444 Registered camera /base/soc/i2c0mux/i2c@1/imx477@1a to Unicam device /dev/media0 and ISP device /dev/media2
[0:09:04.159575135] [2065]  INFO RPI pipeline_base.cpp:1142 Using configuration file '/usr/share/libcamera/pipeline/rpi/vc4/rpi_apps.yaml'
Mode selection for 640:480:12:P
    SRGGB10_CSI2P,1332x990/0 - Score: 1305.05
    SRGGB12_CSI2P,2028x1080/0 - Score: 701.167
    SRGGB12_CSI2P,2028x1520/0 - Score: 607.329
    SRGGB12_CSI2P,4056x3040/0 - Score: 1494.33
[0:09:04.161283879] [2062]  INFO Camera camera.cpp:1183 configuring streams: (0) 640x480-YUV420 (1) 2028x1520-SBGGR12_CSI2P
[0:09:04.161830485] [2065]  INFO RPI vc4.cpp:608 Sensor: /base/soc/i2c0mux/i2c@1/imx477@1a - Selected sensor format: 2028x1520-SBGGR12_1X12 - Selected unicam format: 2028x1520-pBCC
[0:09:07.702015664] [2071] ERROR IPARPI cam_helper.cpp:225 Embedded data buffer parsing failed
[0:09:07.715298802] [2071] ERROR IPARPI cam_helper.cpp:225 Embedded data buffer parsing failed
[0:09:16.716175115] [2065]  WARN V4L2 v4l2_videodevice.cpp:2007 /dev/video0[13:cap]: Dequeue timer of 9000000.00us has expired!
[0:09:16.716431094] [2065] ERROR RPI pipeline_base.cpp:1374 Camera frontend has timed out!
[0:09:16.716556834] [2065] ERROR RPI pipeline_base.cpp:1375 Please check that your camera sensor connector is attached securely.
[0:09:16.716674833] [2065] ERROR RPI pipeline_base.cpp:1376 Alternatively, try another cable and/or sensor.
ERROR: Device timeout detected, attempting a restart!!!
^Z
[1]+  Stopped                 rpicam-vid --frames 100 --nopreview -o sink.h264

Full verbose error log $ rpicam-vid --frames 100 --nopreview -o sink.h264 -v

[0:10:43.967897114] [2100]  INFO Camera camera_manager.cpp:284 libcamera v0.1.0+118-563cd78e
[0:10:44.023426176] [2103]  WARN RPiSdn sdn.cpp:39 Using legacy SDN tuning - please consider moving SDN inside rpi.denoise
[0:10:44.026057523] [2103]  INFO RPI vc4.cpp:444 Registered camera /base/soc/i2c0mux/i2c@1/imx477@1a to Unicam device /dev/media0 and ISP device /dev/media2
[0:10:44.026140467] [2103]  INFO RPI pipeline_base.cpp:1142 Using configuration file '/usr/share/libcamera/pipeline/rpi/vc4/rpi_apps.yaml'
Options:
    verbose: 2
    info_text:
    timeout: 5000ms
    width: 640
    height: 480
    output: sink.h264
    post_process_file:
    preview: none
    qt-preview: 0
    transform: identity
    roi: all
    metering: centre
    exposure: normal
    ev: 0
    awb: auto
    flush: false
    wrap: 0
    brightness: 0
    contrast: 1
    saturation: 1
    sharpness: 1
    framerate: 30
    denoise: auto
    viewfinder-width: 0
    viewfinder-height: 0
    tuning-file: (libcamera)
    lores-width: 0
    lores-height: 0
    autofocus-range: normal
    autofocus-speed: normal
    autofocus-window: all
    hdr: off
    mode: unspecified
    viewfinder-mode: unspecified
    metadata:
    metadata-format: json
    bitrate: 0kbps
    profile:
    level:
    intra: 0
    inline: 0
    save-pts:
    codec: h264
    quality (for MJPEG): 50
    keypress: 0
    signal: 0
    initial: record
    split: 0
    segment: 0
    circular: 0
Running without preview window
Opening camera...
Acquired camera /base/soc/i2c0mux/i2c@1/imx477@1a
Configuring video...
Mode selection for 640:480:12:P
    SRGGB10_CSI2P,1332x990/0 - Score: 1305.05
    SRGGB12_CSI2P,2028x1080/0 - Score: 701.167
    SRGGB12_CSI2P,2028x1520/0 - Score: 607.329
    SRGGB12_CSI2P,4056x3040/0 - Score: 1494.33
[0:10:44.028780166] [2100]  INFO Camera camera.cpp:1183 configuring streams: (0) 640x480-YUV420 (1) 2028x1520-SBGGR12_CSI2P
[0:10:44.029220513] [2103]  INFO RPI vc4.cpp:608 Sensor: /base/soc/i2c0mux/i2c@1/imx477@1a - Selected sensor format: 2028x1520-SBGGR12_1X12 - Selected unicam format: 2028x1520-pBCC
Camera streams configured
Available controls:
    Sharpness : [0.000000..16.000000]
    AwbEnable : [false..true]
    Contrast : [0.000000..32.000000]
    Saturation : [0.000000..32.000000]
    Brightness : [-1.000000..1.000000]
    AeFlickerPeriod : [100..1000000]
    HdrMode : [0..4]
    ColourGains : [0.000000..32.000000]
    ScalerCrop : [(0, 0)/128x128..(0, 0)/4056x3040]
    ExposureTime : [60..0]
    AeEnable : [false..true]
    NoiseReductionMode : [0..4]
    AeConstraintMode : [0..3]
    FrameDurationLimits : [24994..674193371]
    AnalogueGain : [1.000000..22.260870]
    AeFlickerMode : [0..1]
    AwbMode : [0..7]
    AeMeteringMode : [0..3]
    AeExposureMode : [0..3]
    ExposureValue : [-8.000000..8.000000]
Buffers allocated and mapped
Video setup complete
Opened H264Encoder on /dev/video11 as fd 32
Got 6 output buffers
Got 12 capture buffers
Codec streaming started
Requests created
Camera started!
[0:10:47.158400564] [2109] ERROR IPARPI cam_helper.cpp:225 Embedded data buffer parsing failed
[0:10:47.171973351] [2109] ERROR IPARPI cam_helper.cpp:225 Embedded data buffer parsing failed
[0:10:56.178417303] [2103]  WARN V4L2 v4l2_videodevice.cpp:2007 /dev/video0[13:cap]: Dequeue timer of 9000000.00us has expired!
[0:10:56.178597839] [2103] ERROR RPI pipeline_base.cpp:1374 Camera frontend has timed out!
[0:10:56.178660468] [2103] ERROR RPI pipeline_base.cpp:1375 Please check that your camera sensor connector is attached securely.
[0:10:56.178720208] [2103] ERROR RPI pipeline_base.cpp:1376 Alternatively, try another cable and/or sensor.
ERROR: Device timeout detected, attempting a restart!!!
Camera stopped!
Requests created
Camera started!
^Z
[1]+  Stopped                 rpicam-vid --frames 100 --nopreview -o sink.h264 -v

Swapping source and sink The error stays he same. Converting Raspberry Pi n.1 from old sink to new source

$ sudo su
# echo 1 > /sys/module/imx477/parameters/trigger_mode

Converting Pi n.2 from old source to new sink

$ sudo su
# echo 2 > /sys/module/imx477/parameters/trigger_mode

Output of Pi n.2 (now a sink) $ libcamera-vid --frames 100 -o sink.h264

[0:35:47.102698974] [2124]  INFO Camera camera_manager.cpp:284 libcamera v0.1.0+118-563cd78e
[0:35:47.156844345] [2127]  WARN RPiSdn sdn.cpp:39 Using legacy SDN tuning - please consider moving SDN inside rpi.denoise
[0:35:47.159374904] [2127]  INFO RPI vc4.cpp:444 Registered camera /base/soc/i2c0mux/i2c@1/imx477@1a to Unicam device /dev/media4 and ISP device /dev/media1
[0:35:47.159502125] [2127]  INFO RPI pipeline_base.cpp:1142 Using configuration file '/usr/share/libcamera/pipeline/rpi/vc4/rpi_apps.yaml'
Preview window unavailable
Mode selection for 640:480:12:P
    SRGGB10_CSI2P,1332x990/0 - Score: 1305.05
    SRGGB12_CSI2P,2028x1080/0 - Score: 701.167
    SRGGB12_CSI2P,2028x1520/0 - Score: 607.329
    SRGGB12_CSI2P,4056x3040/0 - Score: 1494.33
[0:35:47.161626782] [2124]  INFO Camera camera.cpp:1183 configuring streams: (0) 640x480-YUV420 (1) 2028x1520-SBGGR12_CSI2P
[0:35:47.162076499] [2127]  INFO RPI vc4.cpp:608 Sensor: /base/soc/i2c0mux/i2c@1/imx477@1a - Selected sensor format: 2028x1520-SBGGR12_1X12 - Selected unicam format: 2028x1520-pBCC
[0:35:50.985146733] [2133] ERROR IPARPI cam_helper.cpp:225 Embedded data buffer parsing failed
[0:35:50.998709798] [2133] ERROR IPARPI cam_helper.cpp:225 Embedded data buffer parsing failed
[0:36:00.000167782] [2127]  WARN V4L2 v4l2_videodevice.cpp:2007 /dev/video0[13:cap]: Dequeue timer of 9000000.00us has expired!
[0:36:00.000405020] [2127] ERROR RPI pipeline_base.cpp:1374 Camera frontend has timed out!
[0:36:00.000526796] [2127] ERROR RPI pipeline_base.cpp:1375 Please check that your camera sensor connector is attached securely.
[0:36:00.000643221] [2127] ERROR RPI pipeline_base.cpp:1376 Alternatively, try another cable and/or sensor.
ERROR: Device timeout detected, attempting a restart!!!
^Z
[1]+  Stopped                 libcamera-vid --frames 100 -o sink.h264

Again, ERROR IPARPI cam_helper.cpp:225 Embedded data buffer parsing failed happens when I start the source.

naushir commented 11 months ago

Can you enable full libcamera logging by setting the following environment variable:

export LIBCAMERA_LOG_LEVELS=*:0

Ignoring the embedded buffer parsing error, you are still seeing timeouts after 10s. This should definitely not happen. Are these standard Raspberry Pi HQ camera boards you are using?

lindlou commented 11 months ago

Yes I am using the standard Pi HQ camera v1.0 I set the timeout myself in /usr/share/libcamera/pipeline/rpi/vc4/rpi_apps.yaml, otherwise it would be 1s. Here is the log error_log.txt

naushir commented 11 months ago

It's very hard to say, but it feels like the pulses are not triggering correctly from the source. Are you able to attach a logic analyser to the source sync signal and see what the pulses look like?

lindlou commented 11 months ago

I don't have a logic analyzer, but a multimeter with a min max feature. The voltage on the XVS line is 0.42V, and when the source starts recording the max jumps to 1.73V.

I reflashed the SD cards with Raspberry Pi OS and did an apt upgrade, but the bug is still the same. I can try to make a logic analyzer with an arduino or Pi micro.

naushir commented 11 months ago

Adding @njhollinghurst who might be interested in this.

Unfortunately I won't be able to try this out until next week at the earliest. @njhollinghurst did you ever try 2x IMX477 running in sync?

lindlou commented 11 months ago

A colleague lend me an oscilloscope, and the trigger signal looks fine: oscilloscope I timed 10 seconds by hand with my phone and the oscilloscope triggered 280 times, which is about consistent with a framerate of 30 fps. So the problem must be in the sink.

MitchFuchs commented 9 months ago

Any information on this issue? I run into the same ERROR.

Thanks, MItch

njhollinghurst commented 9 months ago

Ah. It could be a documentation error. In a recent (well-meaning but wrong) documentation change, the recommended pull-up was changed from 1K:1K to 10K:10K, which may be too weak to keep XVS high when the source camera is inactive. It might be confusing the sink camera. A stop-gap solution is to replace the pull-up with a stronger one, e.g. 1K:1K.

Alternatively, try manually enabling the source camera and set its "always-on" parameter.

camera_auto_detect=0
dtoverlay=imx477,always-on
MitchFuchs commented 9 months ago

@njhollinghurst: thanks for your reply. I changed the resistors to 1K:1K and tried 2 scenarios:

1) with the original config file on source and sink 2) with the modified config file on source and original config on sink.

Neither solution works, both return the ERROR 'Embedded data buffer parsing failed'

Questions: a) should I also modify the config file on sink RPI? b) should I run 'sudo rpi-update pulls/5774' as suggested in https://forums.raspberrypi.com/viewtopic.php?t=360476?

Thanks for you help.

njhollinghurst commented 9 months ago

a) You can, and it's more consistent that way, though theoretically not required. b) Yes. I thought it might have been merged into the latest release by now, but perhaps it has not been.

A useful check might be to measure the quiescent voltage on XVS when both Raspberry Pis are powered but neither camera is streaming, and when the sink is streaming but the source is not started. In both cases it should be 1.65V-1.8V.

MitchFuchs commented 9 months ago

@njhollinghurst Doing a) and b) solved the issue and leads to 2 HQ cameras in sync. Thanks!

Out of scope: can I keep the same approach to have more than 2 HQ cams in sync?

njhollinghurst commented 9 months ago

Yes -- now all cameras need the "always-on" flag, and all Raspberry Pis must be powered up before starting streaming. The cameras have a weak internal pull-up (when powered on), so the external voltage divider should no longer be needed.

Now I had better (1) ensure the modification is publically released; (2) update the documentation!

MitchFuchs commented 9 months ago

Thanks a lot! Can confirm I have 3 HQ cams in perfect sync (without external voltage divider).

Screenshot from 2024-02-01 16-08-07

naushir commented 9 months ago

Resolving now...

MitchFuchs commented 9 months ago

@njhollinghurst quick question to make sure: do the multiple cameras still need to be grounded on RPi pin? Thanks!

njhollinghurst commented 9 months ago

@njhollinghurst quick question to make sure: do the multiple cameras still need to be grounded on RPi pin? Thanks!

They need a common ground, to be sure, and preferably not a loop. Since the signal originates from a camera, then camera to camera wiring seems best.