libcamerify seems to work partly, but motion isn't able to open the device

[joeschmitt]

Starting motion with the libcamerify helper script leads to the following behavior:

libcamerify -d motion -c /home/pi/.motion/motion.conf -l /media/pi/USBVIDEO/motion.log
[0:motion] [NTC] [ALL] conf_load: Processing thread 0 - config file /home/pi/.motion/motion.conf
[0:motion] [ALR] [ALL] conf_cmdparse: Unknown config option "
"
[0:motion] [NTC] [ALL] motion_startup: Logging to file (/media/pi/USBVIDEO/motion.log)
[0:29:40.002029132] [5366] INFO Camera camera_manager.cpp:299 libcamera v0.0.3+40-9b860a66
[0:29:40.128392311] [5367] INFO RPI raspberrypi.cpp:1425 Registered camera /base/soc/i2c0mux/i2c@1/imx708@1a to Unicam device /dev/media4 and ISP device /dev/media0
[0:29:40.128564532] [5366] DEBUG V4L2Compat v4l2_compat_manager.cpp:79 Started camera manager
[0:29:40.128704328] [5366] DEBUG V4L2Compat v4l2_camera_proxy.cpp:50 [] open()
[0:29:40.129057344] [5366] DEBUG V4L2Compat v4l2_compat_manager.cpp:163 Opened /dev/video0 -> fd 8
[0:29:40.129230602] [5366] DEBUG V4L2Compat v4l2_camera_proxy.cpp:739 [/dev/video0 (fd:8)] vidioc_streamoff()
[0:29:40.129259879] [5366] DEBUG V4L2Compat v4l2_camera_proxy.cpp:85 [/dev/video0 (fd:8)] close()
[0:29:40.217066672] [5366] DEBUG V4L2Compat v4l2_camera_proxy.cpp:50 [] open()
[0:29:40.217502299] [5366] DEBUG V4L2Compat v4l2_compat_manager.cpp:163 Opened /dev/video0 -> fd 8
[0:29:40.217595446] [5366] DEBUG V4L2Compat v4l2_camera_proxy.cpp:739 [/dev/video0 (fd:8)] vidioc_streamoff()
[0:29:40.217622780] [5366] DEBUG V4L2Compat v4l2_camera_proxy.cpp:85 [/dev/video0 (fd:8)] close()
[0:29:49.955948844] [5366] DEBUG V4L2Compat v4l2_camera_proxy.cpp:50 [] open()
[0:29:49.956718228] [5366] DEBUG V4L2Compat v4l2_compat_manager.cpp:163 Opened /dev/video0 -> fd 8
[0:29:49.956928208] [5366] DEBUG V4L2Compat v4l2_camera_proxy.cpp:739 [/dev/video0 (fd:8)] vidioc_streamoff()
[0:29:49.956983263] [5366] DEBUG V4L2Compat v4l2_camera_proxy.cpp:85 [/dev/video0 (fd:8)] close()

and my motion log shows:

....
[1:ml1] [NTC] [ALL] [Feb 26 18:03:30] motion_init: Camera 0 started: motion detection Enabled
[1:ml1] [NTC] [VID] [Feb 26 18:03:30] vid_start: Opening V4L2 device
[1:ml1] [DBG] [ALL] [Feb 26 18:03:30] util_parms_add: Parsed: >palette< >17<
[1:ml1] [DBG] [ALL] [Feb 26 18:03:30] util_parms_add: Parsed: >input< >-1<
[1:ml1] [DBG] [ALL] [Feb 26 18:03:30] util_parms_add: Parsed: >norm< >0<
[1:ml1] [DBG] [ALL] [Feb 26 18:03:30] util_parms_add: Parsed: >frequency< >0<
[1:ml1] [NTC] [VID] [Feb 26 18:03:30] v4l2_device_open: Using videodevice /dev/video0 and input -1
[1:ml1] [ERR] [VID] [Feb 26 18:03:30] v4l2_device_capability: Not a V4L2 device?
[1:ml1] [DBG] [VID] [Feb 26 18:03:30] v4l2_device_close: close
[1:ml1] [DBG] [VID] [Feb 26 18:03:30] v4l2_device_cleanup: vid_source
[1:ml1] [ERR] [VID] [Feb 26 18:03:30] vid_start: V4L2 device failed to open
.......

It seems the call to xioctl(vid_source, VIDIOC_QUERYCAP, &vid_source->cap) in motion leads to a negative ret code:

.\motion-master\src\video_v4l2.c line 1496
....
static int v4l2_device_capability(struct video_dev *curdev)
{

src_v4l2_t *vid_source = (src_v4l2_t *) curdev->v4l2_private;

if (xioctl(vid_source, VIDIOC_QUERYCAP, &vid_source->cap) < 0) {
    MOTION_LOG(ERR, TYPE_VIDEO, NO_ERRNO, _("Not a V4L2 device?"));
    return -1;
}

MOTION_LOG(DBG, TYPE_VIDEO, NO_ERRNO, "------------------------");
MOTION_LOG(DBG, TYPE_VIDEO, NO_ERRNO, "cap.driver: \"%s\"",vid_source->cap.driver);
MOTION_LOG(DBG, TYPE_VIDEO, NO_ERRNO, "cap.card: \"%s\"",vid_source->cap.card);
MOTION_LOG(DBG, TYPE_VIDEO, NO_ERRNO, "cap.bus_info: \"%s\"",vid_source->cap.bus_info);
MOTION_LOG(DBG, TYPE_VIDEO, NO_ERRNO, "cap.capabilities=0x%08X",vid_source->cap.capabilities);
MOTION_LOG(DBG, TYPE_VIDEO, NO_ERRNO, "------------------------");

....

The camera (Camer V3 with imx708) works fine when I check this with libcamera-vid. And feeding the data through a nginx server (rmtp) which can the motion read from does also work but it's slow in regard to fps and it needs nearly 100% cpu of an raspi4.
So not my prefered solution :(.

My device is a Raspi4 with 64 Bit bullseye, with motion [0:motion] [NTC] [ALL] [Feb 26 18:03:30] motion_startup: Motion 4.5.1 Started

Any idea for a fix or a work-around?

[kbingham]

Can you paste the whole logs with libcamerify -d -d motion -c /home/pi/.motion/motion.conf -l /media/pi/USBVIDEO/motion.log please? (note the double -d)

I suspect the failure is here:

[1:ml1] [DBG] [ALL] [Feb 26 18:03:30] util_parms_add: Parsed: >input< >-1<

[kbingham]

Is there anything specific in your motion.conf? Or can I test this by simply installing 'motion' ?

[kbingham]

Can motion be configured to output logs to the stdout/stderr to interleave them with the libcamera logs? The output you have is confusing - and seems like not all the calls I would expect to run in the v4l2 layer are being called.

[kbingham]

Specifically, the querycap should be calling into the v4l2 layer at
https://github.com/kbingham/libcamera/blob/master/src/v4l2/v4l2_camera_proxy.cpp#L249...L257

And that function is /really/ short and only returns success...

[kbingham]

libcamerify -d -d ./src/motion -d ALL

[0:35:46.572618635] [11836]  INFO RPI raspberrypi.cpp:1481 Registered camera /base/soc/i2c0mux/i2c@1/imx219@10 to Unicam device /dev/media2 and ISP device /dev/media1
[0:35:46.572808483] [11836] DEBUG Camera camera_manager.cpp:163 Pipeline handler "PipelineHandlerRPi" matched
[0:35:46.572905129] [11836] DEBUG RPI raspberrypi.cpp:1255 Unable to acquire a Unicam instance
[0:35:46.572966776] [11836] DEBUG Camera camera_manager.cpp:151 Found registered pipeline handler 'PipelineHandlerRkISP1'
[0:35:46.573187957] [11836] DEBUG Camera camera_manager.cpp:151 Found registered pipeline handler 'SimplePipelineHandler'
[0:35:46.573348268] [11836] DEBUG Camera camera_manager.cpp:151 Found registered pipeline handler 'PipelineHandlerUVC'
[0:35:46.573464784] [11836] DEBUG Camera camera_manager.cpp:151 Found registered pipeline handler 'PipelineHandlerVimc'
[0:35:46.573677613] [11835] DEBUG V4L2Compat v4l2_compat_manager.cpp:79 Started camera manager
[0:35:46.574184751] [11835] DEBUG V4L2Compat v4l2_camera_proxy.cpp:50 [] open()
[0:35:46.575997252] [11835] DEBUG RPI raspberrypi.cpp:631 Try color space sYCC
[0:35:46.576606573] [11835] DEBUG Camera camera.cpp:969 streams configuration: (0) 800x600-NV12
[0:35:46.576929734] [11835] DEBUG V4L2Compat v4l2_compat_manager.cpp:163 Opened /dev/video0 -> fd 4
[1:ml1] [ERR] [VID] v4l2_device_capability: Not a V4L2 device?
[0:35:46.577509944] [11835] DEBUG V4L2Compat v4l2_camera_proxy.cpp:739 [/dev/video0 (fd:4)] vidioc_streamoff()
[0:35:46.577775180] [11835] DEBUG V4L2Compat v4l2_camera_proxy.cpp:85 [/dev/video0 (fd:4)] close()
[1:ml1] [ERR] [VID] vid_start: V4L2 device failed to open
[1:ml1] [WRN] [ALL] motion_init: Could not fetch initial image from camera 
[1:ml1] [WRN] [ALL] motion_init: Motion continues using width and height from config file(s)
[1:ml1] [NTC] [ALL] image_ring_resize: Resizing pre_capture buffer to 1 items
[1:ml1] [WRN] [ALL] mlp_retry: Retrying until successful connection with camera
[1:ml1] [NTC] [VID] vid_start: Opening V4L2 device
[1:ml1] [NTC] [VID] v4l2_device_open: Using videodevice /dev/video0 and input -1
[0:35:49.989406426] [11835] DEBUG V4L2Compat v4l2_camera_proxy.cpp:50 [] open()
[0:35:49.990606217] [11835] DEBUG RPI raspberrypi.cpp:631 Try color space sYCC
[0:35:49.991005283] [11835] DEBUG Camera camera.cpp:969 streams configuration: (0) 800x600-NV12
[0:35:49.991277704] [11835] DEBUG V4L2Compat v4l2_compat_manager.cpp:163 Opened /dev/video0 -> fd 4
[1:ml1] [ERR] [VID] v4l2_device_capability: Not a V4L2 device?
[0:35:49.991690251] [11835] DEBUG V4L2Compat v4l2_camera_proxy.cpp:739 [/dev/video0 (fd:4)] vidioc_streamoff()
[0:35:49.991875210] [11835] DEBUG V4L2Compat v4l2_camera_proxy.cpp:85 [/dev/video0 (fd:4)] close()
[1:ml1] [ERR] [VID] vid_start: V4L2 device failed to open
[1:ml1] [WRN] [ALL] mlp_retry: Retrying until successful connection with camera
[1:ml1] [NTC] [VID] vid_start: Opening V4L2 device
[1:ml1] [NTC] [VID] v4l2_device_open: Using videodevice /dev/video0 and input -1
[0:36:00.000887389] [11835] DEBUG V4L2Compat v4l2_camera_proxy.cpp:50 [] open()
[0:36:00.003015902] [11835] DEBUG RPI raspberrypi.cpp:631 Try color space sYCC
[0:36:00.003319507] [11835] DEBUG Camera camera.cpp:969 streams configuration: (0) 800x600-NV12
[0:36:00.003528540] [11835] DEBUG V4L2Compat v4l2_compat_manager.cpp:163 Opened /dev/video0 -> fd 4
[1:ml1] [ERR] [VID] v4l2_device_capability: Not a V4L2 device?
[0:36:00.004487521] [11835] DEBUG V4L2Compat v4l2_camera_proxy.cpp:739 [/dev/video0 (fd:4)] vidioc_streamoff()
[0:36:00.004645000] [11835] DEBUG V4L2Compat v4l2_camera_proxy.cpp:85 [/dev/video0 (fd:4)] close()
[1:ml1] [ERR] [VID] vid_start: V4L2 device failed to open
^C[0:motion] [NTC] [ALL] sig_handler: Received signal 2.
[1:ml1] [NTC] [ALL] motion_loop: Thread exiting
[0:motion] [NTC] [ALL] main: Threads finished
[0:motion] [NTC] [ALL] main: Motion terminating

The 'open' call is being made through the v4l2-adaption layer - but the other ioctls are not. I wonder if it's trying to use libv4l or something which is intercepting the calls and breaking the libcamera v4l2 layer.

[joeschmitt]

Hi,
I made the logs as you suggested. (I assumend the double -d was a typing issue :( )

pi@raspberrypi:~ $ libcamerify -d -d motion -c /home/pi/.motion/motion.conf -l /media/pi/USBVIDEO/motion.log
[0:motion] [NTC] [ALL] conf_load: Processing thread 0 - config file /home/pi/.motion/motion.conf
[0:motion] [ALR] [ALL] conf_cmdparse: Unknown config option "
"
[0:motion] [NTC] [ALL] motion_startup: Logging to file (/media/pi/USBVIDEO/motion.log)
[0:05:14.129382141] [2224] DEBUG IPAModule ipa_module.cpp:329 ipa_rpi.so: IPA module /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi.so is signed
[0:05:14.130046002] [2224] DEBUG IPAManager ipa_manager.cpp:245 Loaded IPA module '/usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi.so'
[0:05:14.132548633] [2224] DEBUG IPAModule ipa_module.cpp:329 ipa_vimc.so: IPA module /usr/lib/aarch64-linux-gnu/libcamera/ipa_vimc.so is signed
[0:05:14.132684187] [2224] DEBUG IPAManager ipa_manager.cpp:245 Loaded IPA module '/usr/lib/aarch64-linux-gnu/libcamera/ipa_vimc.so'
[0:05:14.132766796] [2224] INFO Camera camera_manager.cpp:299 libcamera v0.0.3+40-9b860a66
[0:05:14.133095310] [2225] DEBUG Camera camera_manager.cpp:108 Starting camera manager
[0:05:14.143336535] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:224 New media device "rpivid" created from /dev/media3
[0:05:14.143487662] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:95 Defer media device /dev/media3 due to 1 missing dependencies
[0:05:14.144168782] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:320 All dependencies for media device /dev/media3 found
[0:05:14.144246207] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:252 Added device /dev/media3: rpivid
[0:05:14.144737033] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:224 New media device "bcm2835-codec" created from /dev/media4
[0:05:14.144800532] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:95 Defer media device /dev/media4 due to 5 missing dependencies
[0:05:14.147851693] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:320 All dependencies for media device /dev/media4 found
[0:05:14.147973746] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:252 Added device /dev/media4: bcm2835-codec
[0:05:14.148498887] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:224 New media device "bcm2835-isp" created from /dev/media0
[0:05:14.148571738] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:95 Defer media device /dev/media0 due to 4 missing dependencies
[0:05:14.148950603] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:224 New media device "bcm2835-isp" created from /dev/media1
[0:05:14.149004621] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:95 Defer media device /dev/media1 due to 4 missing dependencies
[0:05:14.151364661] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:320 All dependencies for media device /dev/media0 found
[0:05:14.151489196] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:252 Added device /dev/media0: bcm2835-isp
[0:05:14.153698572] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:320 All dependencies for media device /dev/media1 found
[0:05:14.153806645] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:252 Added device /dev/media1: bcm2835-isp
[0:05:14.154734817] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:224 New media device "unicam" created from /dev/media2
[0:05:14.155459140] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:95 Defer media device /dev/media2 due to 2 missing dependencies
[0:05:14.156955655] [2225] DEBUG DeviceEnumerator device_enumerator_udev.cpp:320 All dependencies for media device /dev/media2 found
[0:05:14.157058154] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:252 Added device /dev/media2: unicam
[0:05:14.157817773] [2225] DEBUG Camera camera_manager.cpp:151 Found registered pipeline handler 'PipelineHandlerRPi'
[0:05:14.162738665] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:312 Successful match for media device "unicam"
[0:05:14.162980366] [2225] DEBUG DeviceEnumerator device_enumerator.cpp:312 Successful match for media device "bcm2835-isp"
[0:05:14.163571783] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Exposure (0x00980911)
[0:05:14.163959981] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Horizontal Flip (0x00980914)
[0:05:14.164073109] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Vertical Flip (0x00980915)
[0:05:14.164128109] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Wide Dynamic Range (0x009a0915)
[0:05:14.164180552] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Camera Orientation (0x009a0922)
[0:05:14.164253311] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Camera Sensor Rotation (0x009a0923)
[0:05:14.164516436] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Vertical Blanking (0x009e0901)
[0:05:14.164624194] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Horizontal Blanking (0x009e0902)
[0:05:14.164727841] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Analogue Gain (0x009e0903)
[0:05:14.164794914] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Red Pixel Value (0x009e0904)
[0:05:14.164858302] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Green (Red) Pixel Value (0x009e0905)
[0:05:14.164932116] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Blue Pixel Value (0x009e0906)
[0:05:14.164994707] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Green (Blue) Pixel Value (0x009e0907)
[0:05:14.165069058] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Notify Gains (0x009e0909)
[0:05:14.165185816] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Pixel Rate (0x009f0902)
[0:05:14.165271500] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Test Pattern (0x009f0903)
[0:05:14.165364850] [2225] DEBUG V4L2 v4l2_device.cpp:635 'imx708': Control: Digital Gain (0x009f0905)
[0:05:14.255612267] [2225] DEBUG V4L2 v4l2_device.cpp:635 'dw9807 10-000c': Control: Focus, Absolute (0x009a090a)
[0:05:14.256160630] [2225] DEBUG CameraSensor camera_sensor.cpp:639 'imx708': Apply test pattern mode 0
[0:05:14.267788464] [2225] DEBUG IPAManager ipa_manager.cpp:303 IPA module /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi.so signature is valid
[0:05:14.268085979] [2225] DEBUG IPAProxy raspberrypi_ipa_proxy.cpp:45 initializing raspberrypi proxy: loading IPA from /usr/lib/aarch64-linux-gnu/libcamera/ipa_rpi.so
[0:05:14.286085537] [2225] DEBUG RPiBlackLevel black_level.cpp:41 Read black levels red 4096 green 4096 blue 4096
[0:05:14.286551975] [2225] DEBUG RPiAgc agc.cpp:250 Agc
[0:05:14.286626603] [2225] DEBUG RPiAgc agc.cpp:187 AgcConfig
[0:05:14.287016061] [2225] DEBUG RPiAlsc alsc.cpp:138 Read calibrations_Cr calibration for ct 3000
[0:05:14.287205262] [2225] DEBUG RPiAlsc alsc.cpp:138 Read calibrations_Cr calibration for ct 5000
[0:05:14.287326130] [2225] DEBUG RPiAlsc alsc.cpp:138 Read calibrations_Cb calibration for ct 3000
[0:05:14.287444388] [2225] DEBUG RPiAlsc alsc.cpp:138 Read calibrations_Cb calibration for ct 5000
[0:05:14.287613200] [2225] DEBUG RPiSharpen sharpen.cpp:45 Read threshold 1 strength 1 limit 1
[0:05:14.288356171] [2225] DEBUG V4L2 v4l2_videodevice.cpp:632 /dev/video0[19:cap]: Opened device platform:fe801000.csi: unicam: unicam
[0:05:14.288764350] [2225] DEBUG V4L2 v4l2_videodevice.cpp:632 /dev/video1[20:cap]: Opened device platform:fe801000.csi: unicam: unicam
[0:05:14.288925515] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Red Balance (0x0098090e)
[0:05:14.289019588] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Blue Balance (0x0098090f)
[0:05:14.289090068] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Colour Correction Matrix (0x009819e1)
[0:05:14.289145715] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Lens Shading (0x009819e2)
[0:05:14.289203196] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Black Level (0x009819e3)
[0:05:14.289258417] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Green Equalisation (0x009819e4)
[0:05:14.289315380] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Gamma (0x009819e5)
[0:05:14.289367749] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Denoise (0x009819e6)
[0:05:14.289424323] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Sharpen (0x009819e7)
[0:05:14.289483137] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Defective Pixel Correction (0x009819e8)
[0:05:14.289539284] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Colour Denoise (0x009819e9)
[0:05:14.289594561] [2225] DEBUG V4L2 v4l2_device.cpp:635 /dev/video13[21:cap]: Control: Digital Gain (0x009f0905)
[0:05:14.289680504] [2225] DEBUG V4L2 v4l2_videodevice.cpp:632 /dev/video13[21:out]: Opened device platform:bcm2835-isp: bcm2835-isp: bcm2835-isp
[0:05:14.289919056] [2225] DEBUG V4L2 v4l2_videodevice.cpp:632 /dev/video14[22:cap]: Opened device platform:bcm2835-isp: bcm2835-isp: bcm2835-isp
[0:05:14.290023870] [2225] DEBUG V4L2 v4l2_videodevice.cpp:632 /dev/video15[23:cap]: Opened device platform:bcm2835-isp: bcm2835-isp: bcm2835-isp
[0:05:14.290106313] [2225] DEBUG V4L2 v4l2_videodevice.cpp:632 /dev/video16[24:cap]: Opened device platform:bcm2835-isp: bcm2835-isp: bcm2835-isp
[0:05:14.290161682] [2225] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 3 and priority write flag 0 for Horizontal Blanking
[0:05:14.290188423] [2225] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 3 and priority write flag 1 for Vertical Blanking
[0:05:14.290210848] [2225] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 2 and priority write flag 0 for Exposure
[0:05:14.290249626] [2225] DEBUG RPiDelayedControls delayed_controls.cpp:103 Set a delay of 2 and priority write flag 0 for Analogue Gain
[0:05:14.290401994] [2225] INFO RPI raspberrypi.cpp:1425 Registered camera /base/soc/i2c0mux/i2c@1/imx708@1a to Unicam device /dev/media2 and ISP device /dev/media0
[0:05:14.290466604] [2225] DEBUG Camera camera_manager.cpp:163 Pipeline handler "PipelineHandlerRPi" matched
[0:05:14.290520362] [2225] DEBUG RPI raspberrypi.cpp:1204 Unable to acquire a Unicam instance
[0:05:14.290566621] [2225] DEBUG Camera camera_manager.cpp:151 Found registered pipeline handler 'SimplePipelineHandler'
[0:05:14.290663823] [2225] DEBUG Camera camera_manager.cpp:151 Found registered pipeline handler 'PipelineHandlerUVC'
[0:05:14.290713341] [2225] DEBUG Camera camera_manager.cpp:151 Found registered pipeline handler 'PipelineHandlerVimc'
[0:05:14.292243208] [2224] DEBUG V4L2Compat v4l2_compat_manager.cpp:79 Started camera manager
[0:05:14.292428298] [2224] DEBUG V4L2Compat v4l2_camera_proxy.cpp:50 [] open()
[0:05:14.292815996] [2224] DEBUG RPI raspberrypi.cpp:576 Try color space sYCC
[0:05:14.292884051] [2224] DEBUG Camera camera.cpp:969 streams configuration: (0) 800x600-NV12
[0:05:14.292946920] [2224] DEBUG V4L2Compat v4l2_compat_manager.cpp:163 Opened /dev/video0 -> fd 8
[0:05:14.293135844] [2224] DEBUG V4L2Compat v4l2_camera_proxy.cpp:739 [/dev/video0 (fd:8)] vidioc_streamoff()
[0:05:14.293169991] [2224] DEBUG V4L2Compat v4l2_camera_proxy.cpp:85 [/dev/video0 (fd:8)] close()
[0:05:14.509936569] [2224] DEBUG V4L2Compat v4l2_camera_proxy.cpp:50 [] open()
[0:05:14.510311878] [2224] DEBUG RPI raspberrypi.cpp:576 Try color space sYCC
[0:05:14.510369785] [2224] DEBUG Camera camera.cpp:969 streams configuration: (0) 800x600-NV12
[0:05:14.510408136] [2224] DEBUG V4L2Compat v4l2_compat_manager.cpp:163 Opened /dev/video0 -> fd 8
[0:05:14.510494672] [2224] DEBUG V4L2Compat v4l2_camera_proxy.cpp:739 [/dev/video0 (fd:8)] vidioc_streamoff()
[0:05:14.510521579] [2224] DEBUG V4L2Compat v4l2_camera_proxy.cpp:85 [/dev/video0 (fd:8)] close()
[0:05:24.501981011] [2224] DEBUG V4L2Compat v4l2_camera_proxy.cpp:50 [] open()
[0:05:24.502730372] [2224] DEBUG RPI raspberrypi.cpp:576 Try color space sYCC
[0:05:24.502871833] [2224] DEBUG Camera camera.cpp:969 streams configuration: (0) 800x600-NV12
[0:05:24.503202533] [2224] DEBUG V4L2Compat v4l2_compat_manager.cpp:163 Opened /dev/video0 -> fd 8
[0:05:24.504179039] [2224] DEBUG V4L2Compat v4l2_camera_proxy.cpp:739 [/dev/video0 (fd:8)] vidioc_streamoff()
[0:05:24.504272723] [2224] DEBUG V4L2Compat v4l2_camera_proxy.cpp:85 [/dev/video0 (fd:8)] close()
motion.log
motion.conf.txt

I attached also the log of motion (level all == 9) and also my motion config file.

I made a fresh bullseye installation an also motion was a fresh install, so nothing special involved which could interfere as far as i know.

Thanks

[joeschmitt]

[1:ml1] [DBG] [ALL] [Feb 27 09:00:25] util_parms_add: Parsed: >input< >-1<
for this result in the motion log I found no reason based on motion.conf. One idea I had that the space at the beginning of 👍 noise_level 40
could be a reason due to a parsing bug. So I removed them but no change.

[joeschmitt]

In motion file video_common.c I found the following function:
/* vid_parms_parse

• Parse the video_params into an array.
  */
  void vid_parms_parse(struct context *cnt)
  {

  int indx;

  if (cnt->vdev->update_params == FALSE) {
  return;
  }

  /* Put in the user specified parameters */
  util_parms_parse(cnt->vdev, cnt->conf.video_params, TRUE);

  /* Now add any missing default items */
  util_parms_add_default(cnt->vdev,"palette","17");
  util_parms_add_default(cnt->vdev,"input","-1");
  util_parms_add_default(cnt->vdev,"norm","0");
  util_parms_add_default(cnt->vdev,"frequency","0");

  for (indx = 0; indx < cnt->vdev->params_count; indx++) {
  if (mystreq(cnt->vdev->params_array[indx].param_name, "input")) {
  cnt->param_input = atoi(cnt->vdev->params_array[indx].param_value);
  }
  if (mystreq(cnt->vdev->params_array[indx].param_name, "norm")) {
  cnt->param_norm = atoi(cnt->vdev->params_array[indx].param_value);
  }
  if (mystreq(cnt->vdev->params_array[indx].param_name, "frequency")) {
  cnt->param_freq = atol(cnt->vdev->params_array[indx].param_value);
  }
  }

  cnt->vdev->update_params = FALSE;

  return;

}

So the part /* Now add any missing default items */

explains to me why in the motion log those lines show up without been given in the motion.conf

[kbingham]

Ok - your logs looks similar to the ones I made. Could you raise this somewhere with motion to ask if they do anything that would otherwise prevent an LD_PRELOAD library from intercepting ioctls to a V4L2 video device? (That's what I think is failing)

[joeschmitt]

Ok I will do as you proposed. Thanks for your analyze in the meanwhile

[kbingham]

(Please report back here too of course, or cross link the issues so I can subscribe to see / discuss on the motion side)

[joeschmitt]

I left a comment for the same topic, as far as I assume and gave them a link to our discussion.
Motion-Project/motion#1636