rsint with network socket for control using ipc

reyalp

13838

Re: rsint with network socket for control using ipc

« Reply #10 on: 09 / September / 2021, 13:26:26 »

Advertisements

Quote from: quesarilla on 09 / September / 2021, 10:54:56

Quote from: reyalp on 08 / September / 2021, 18:45:56
How are you determining when cameras complete the operation?
Program blocks until chdkptp writes to stdout, then check if it is the rsint prompt.

That makes sense. If you use set cli_debug=1, you could check when data becomes available by looking for a line like

Code: [Select]

rc file IMG_4345.jpg 1

The time from when the s was sent and the "file" line will give you an approximation of how long the shooting part took, without needing to modify chdkptp.

Quote

Does the camera autocompensate for exposure if I set them manually? mm that could be a problem.

Here is the command I use to enter rsint mode:
Code: [Select]
rsint /home/pi/images/${serial}/${name} -tv=0.200 -sv=80 -av=11.0 -sd=5m

It shouldn't, though bugs in overrides are possible. If override failed, the exposure wold still be constant for a given rsint invocation, it would just (potentially) vary between separate rsint commands. From your description of the scene, it should be easy to check visually if the exposure is varying between shots or sessions.

For SD override, if the camera is in AF mode, it will autofocus, and the apply the override. This can take variable time, but again only for the initial shot. You can have the camera use MF mode using the -sdmode=MF option.
Just generally for SD override, you should make sure continuous AF and Servo AF are disabled in the Canon options.

One thing that you can try is using continuous mode. To do this, you need to set the drive mode to continuous in the Canon firmware menu, and then use rsint -cont ...
Finally, to end the rsint session, you need to send 'l' for the last shot, because the point where it waits for commands is too late to not shoot.

Continuous mode may be faster overall, and if the slowdown you are seeing is a quirk of the canon firmware, continuous may behave differently.

What canon shooting mode are you using? (M, P, Tv ...)

Quote

I also ran the test on a virtual machine (debian bullseye, amd64, kernel v 5.10) using a single camera and saw the same degradation.
Initial shots took between 1.1s and 1.6s, then around the 20th shot it started to take ~2.6s per shot. Surprisingly it wasn't much faster than running the same on 6 cameras, so I'm guessing that bus speed is not a limiting factor here?

That's quite odd. Is the change within a single rsint session? That is, you enter rsint, shoot ~20 shots then it slows down for the following shots? Or if you invoke rsint 5 times and shoot 5 shots each, does it still slow down around the 20th shot?

Quote

The camera makes a sound when capturing a shot as similar to the one produced when switching between rec and play mode, and it's roughly proportional to the time it takes for the image capture to complete.

Hm, I'm not sure what this means. I would expect only the shutter sound when shooting with rsint. But I usually keep my cams muted.

For fast shooting, you should make sure the "review" setting is turned off in the canon firmware, though again, this shouldn't vary between rsint invocations.

Quote

Quote
FWIW, the current stable CHDK is 1.5.1 and most recent chdkptp release is r964. I'm not aware of any changes that would be directly relevant to your problem, although there were some fixes in the PTP and remoteshoot.
I tried compiling it from sources on the vm I mentioned above but couldn't set up the toolchain properly, kept getting arm-gcc-eabi not found errors.

FWIW, if you aren't using a customized build, you can get builds of 1.5 from the autobuild http://mighty-hoernsche.de/
The 1.6 dev builds are also available http://mighty-hoernsche.de/trunk/
That said, I think it's pretty unlikely that your problem is going to be fixed by switching CHDK builds, so it might be better to stick with what you have for now. Of course, you can always try updating one SD just to see.

If you are using a custom build, it would be good to know how it's been modified.

Logged

Don't forget what the H stands for.

Caefix

900
Sorry, busy deleting test shots...

Re: rsint with network socket for control using ipc

« Reply #11 on: 09 / September / 2021, 14:58:29 »

S110 has aperture_sizes_table defined upto { 21, 576, "8.0" }, is -av=11.0 out of bounds?

« Last Edit: 10 / September / 2021, 10:59:23 by Caefix »

Logged

All lifetime is a loan from eternity.

reyalp

13838

Re: rsint with network socket for control using ipc

« Reply #12 on: 09 / September / 2021, 15:39:18 »

Quote from: Caefix on 09 / September / 2021, 14:58:29

S110 has aperture_sizes_table defined upto { 21, 576, "8.0" }, is -av=11.0 out of bounds?

Probably not. The table normally includes the range available in the Canon UI. The actual range available with set_av96_direct usually goes to 11 or higher. In any case, there is very little chance this has anything to do with the OPs problem.

Logged

Don't forget what the H stands for.

quesarilla

Re: rsint with network socket for control using ipc

« Reply #13 on: 09 / September / 2021, 17:40:05 »

Quote from: Caefix on 09 / September / 2021, 14:58:29

S110 has aperture_sizes_table defined upto { 21, 576, "8.0" }, is -av=11.0 out of bounds?
Ok, could -av=11.0 conflict with zoomposition?

At least the images are considerably darker when taken with av=11.0 compared to av=8.0, all other settings being equal. The Canon UI also shows the aperture as "8 - 2" with the " - 2" in bolded red.

Quote from: reyalp on 09 / September / 2021, 13:26:26

Just generally for SD override, you should make sure continuous AF and Servo AF are disabled in the Canon options.

Yes, AF and MF are disabled at the Canon UI.

Quote

One thing that you can try is using continuous mode. To do this, you need to set the drive mode to continuous in the Canon firmware menu, and then use rsint -cont ...
Finally, to end the rsint session, you need to send 'l' for the last shot, because the point where it waits for commands is too late to not shoot.

Thanks for bringing this to my attention.
The camera array (6 cameras) were tested in P mode.
The single camera test was done in C mode, but I did not pass the -cont flag to rsint.

Quote

Quote
I also ran the test on a virtual machine (debian bullseye, amd64, kernel v 5.10) using a single camera and saw the same degradation.
Initial shots took between 1.1s and 1.6s, then around the 20th shot it started to take ~2.6s per shot. Surprisingly it wasn't much faster than running the same on 6 cameras, so I'm guessing that bus speed is not a limiting factor here?
That's quite odd. Is the change within a single rsint session? That is, you enter rsint, shoot ~20 shots then it slows down for the following shots? Or if you invoke rsint 5 times and shoot 5 shots each, does it still slow down around the 20th shot?

Yes, the slow down happens within a single invocation of rsint.

Quote

For fast shooting, you should make sure the "review" setting is turned off in the canon firmware, though again, this shouldn't vary between rsint invocations.

Yes, that setting has also been set to off.

Quote

If you are using a custom build, it would be good to know how it's been modified.

I'm just using plain vainilla. Building it so that I can power the cameras with the battery cover off would be fairly convenient for debugging power issues, as one of the cameras will sometimes crash while switching from play to rec mode, and I'm thinking it's because of a bad terminal connection.

Logged

reyalp

13838

Re: rsint with network socket for control using ipc

« Reply #14 on: 09 / September / 2021, 18:47:34 »

Quote from: quesarilla on 09 / September / 2021, 17:40:05

Thanks for bringing this to my attention.
The camera array (6 cameras) were tested in P mode.
The single camera test was done in C mode, but I did not pass the -cont flag to rsint.

Note C mode is used for saved custom settings in the Canon firmware (for example, preset exposure, zoom, focus settings etc)

Drive mode is accessed from is accessed from the func menu, and may be Single, Continuous, Continuous AF, or Continuous LV.
To use the -cont switch, this should be set to plain continuous.

Canon specs advertise 2.1 FPS in continuous mode.

Quote

Yes, the slow down happens within a single invocation of rsint.

And if you do another sub 20 shot rsint, it starts fast again?

If so, I'd guess this is some kind of Canon firmware buffering behavior. I'd definitely suggest trying cont mode.

You could use a script like my fixedint.lua https://chdk.fandom.com/wiki/Lua/Scripts:_Fixed_Exposure_Intervalometer to see if it's reproducible without remoteshoot involved. Set
Shots = 40
Interval = 0
Use Raw = No
Tv = 1/64 (not the default 64!)
Use cont mode if set = Unchecked
All other settings default.

When you run the script, it will take 40 shots and create a file called fixedint.csv in the root of the SD card, with timing information for each shot. Specifically, the "sleep" column will be the negative of the shot-to-shot time

To check if cont mode has the same timing behavior, you can repeat with with "Use cont mode if set" checked, and continuous mode enabled in the Canon func menu.

Quote

I'm just using plain vainilla. Building it so that I can power the cameras with the battery cover off would be fairly convenient for debugging power issues, as one of the cameras will sometimes crash while switching from play to rec mode, and I'm thinking it's because of a bad terminal connection.

It doesn't look like the battery door override is implemented on s110, but it should be easy to add.

If you want to build on windows, the stuff in this thread https://chdk.setepontos.com/index.php?topic=12752.0 should be pretty straightforward to get working.

There's also a docker container https://chdk.fandom.com/wiki/Compiling_CHDK_With_Docker that should be pretty easy to set up (if you already have docker working anyway) although I believe you'd have to use the trunk source rather than 1.5. Not much has changed since the 1.5 release, so I would expect it to be about as stable.

Logged

Don't forget what the H stands for.

Caefix

900
Sorry, busy deleting test shots...

Re: rsint with network socket for control using ipc

« Reply #15 on: 10 / September / 2021, 10:52:05 »

Quote from: reyalp on 09 / September / 2021, 13:26:26

Quote from: quesarilla on 09 / September / 2021, 10:54:56
Quote from: reyalp on 08 / September / 2021, 18:45:56
Quote
The camera makes a sound when ...

S110 has

...

Code: [Select]

    #define CAM_HAS_NATIVE_ND_FILTER            1   // Camera has built-in ND filter with Canon menu support for enable/disable
// without
    #undef  CAM_HAS_IRIS_DIAPHRAGM

Maybe -av=11.0 forces ND filter with large aperture /low dof instead of deep dof && av11 ...

Quote

The actual range available with set_av96_direct usually goes to 11 or higher.

Logged

All lifetime is a loan from eternity.

quesarilla

Re: rsint with network socket for control using ipc

« Reply #16 on: 10 / September / 2021, 13:10:54 »

I logged the times as suggested using ticktime.get() and writing to a log file.

The timing for chdku.rc_handler_file() is consistently at 0.5 ticktime units, before and after the delay appears.
The slowdown occurs when calling con:capture_get_data().

If the camera sits in play mode for a while, the initial images taken when invoking rsint again will not see the delay (no reboot needed)

Even with av=2.0 the issue persists.

I ran fixedint.lua 4 consecutive times, with the suggested settings, except 'Shots' was set to 80 but couldn't reproduced the issue.

EDIT:
This line causes the delay. Maybe we are running out of space on the stack, causing lua to call the garbage collector?
Snippet comes from con_methods:capture_get_data() in chdku.lua

Code: [Select]

        t01 = ticktime.get()
        local subst

        -- table to return chunks (or other values) sent by hdata.store_return
        local rets = {}
        t1 = ticktime.get()

Logs from the remote process:
Shot #27 Elapsed time is 1.682494 seconds.
Shot #28 Elapsed time is 1.695019 seconds.
Shot #29 Elapsed time is 1.716617 seconds.
Shot #30 Elapsed time is 2.924171 seconds.
Shot #31 Elapsed time is 2.929019 seconds.
Shot #32 Elapsed time is 2.834076 seconds.

Logs from lua:
27 t0 to t01: 5.6353001127718e-05 t01 to t1: 0.99675145999936t1 to t4: 0.65600149700185
28 t0 to t01: 0.00013392899927567 t01 to t1: 1.0138843540008t1 to t4: 0.6498858820014
29 t0 to t01: 3.6772999010282e-05 t01 to t1: 1.1890429920022t1 to t4: 0.49450209599672
30 t0 to t01: 3.0658000468975e-05 t01 to t1: 2.2420918210009t1 to t4: 0.64652456899785
31 t0 to t01: 6.5438998717582e-05 t01 to t1: 2.2482954400002t1 to t4: 0.64549802200054
32 t0 to t01: 6.7705997935263e-05 t01 to t1: 2.1581319739998t1 to t4: 0.64903791100005

« Last Edit: 10 / September / 2021, 14:06:52 by quesarilla »

Logged

Caefix

900
Sorry, busy deleting test shots...

Re: rsint with network socket for control using ipc

« Reply #17 on: 10 / September / 2021, 14:20:28 »

Quote

the garbage collector?

In that case I´d expect only #shot x%30 off...

Logged

All lifetime is a loan from eternity.

reyalp

13838

Re: rsint with network socket for control using ipc

« Reply #18 on: 10 / September / 2021, 21:17:50 »

Quote from: Caefix on 10 / September / 2021, 10:52:05

Maybe -av=11.0 forces ND filter with large aperture /low dof instead of deep dof && av11 ...

No. On cameras with both, the aperture setting is not connected to the ND. Again, this is really not helpful to the subject of the thread.

Logged

Don't forget what the H stands for.

reyalp

13838

Re: rsint with network socket for control using ipc

« Reply #19 on: 10 / September / 2021, 21:44:06 »

Quote from: quesarilla on 10 / September / 2021, 13:10:54

I ran fixedint.lua 4 consecutive times, with the suggested settings, except 'Shots' was set to 80 but couldn't reproduced the issue.

OK, that definitely suggests it's remoteshoot related.

Quote

EDIT:
This line causes the delay. Maybe we are running out of space on the stack, causing lua to call the garbage collector?

Wouldn't be the stack, but this isn't a bad thought.
Regular (not rsint) remoteshoot has the line

Code: [Select]

collectgarbage('collect') -- keep uncollected lbufs from building up

which runs for each shot. rsint does not.
You could try adding the same line in rsint_once. Right at the start would be fine.
I would be somewhat surprised a garbage collection issue would behave like this across platforms, but it's easy to try and isn't totally implausible.

Note if you want to measure duration with ticktime, you can do something like

Code: [Select]

t0=ticktime.get()
...
print("elapsed time %f\n",ticktime.elapsed(t0))

Quote

27 t0 to t01: 5.6353001127718e-05 t01 to t1: 0.99675145999936t1 to t4: 0.65600149700185

This seems odd. Defining two local variables should not take a noticeable fraction of a second. It should be microseconds. Can you post a diff or the files with the full logging changes?

Logged

Don't forget what the H stands for.