Issue with intermittent remoteshoot behaviour on G7X2

philmoz

3450

« on: 23 / October / 2020, 19:27:59 »

Advertisements

While running the camtests.lua script on the G7X2 I ran into issues where remoteshoot would sometimes fail with a timeout error.
The camera did not crash or drop the PTP connection, just the remoteshoot script would fail to take a shot.

After digging in the code, and with a lot of assistance from reyalp, I found that the remoteshoot script would sometimes not enter 'alt' mode on startup and so all the script key presses would get ignored. This means the shot does not get taken and the script eventually times out waiting for it.

The logic is when a script starts the lua_script_start function will enter 'alt' mode if it's not already in that mode. When the script ends it will exit 'alt' mode if it was not entered by the script starting. Entering alt mode then enables the key presses in the script to be sent to the camera firmware.

The lua_script_start function checks if the camera is in alt mode by checking a flag set in the GUI code (which runs in a different task).

When remoteshoot is used from chdkptp, a number of different scripts are run, then second of which is one that takes the shot.

Using LogCameraEvent I captured the sequence of calls for when it works and when it fails.

This is the call logic for a successful run:

Code: [Select]

00108630: DBG:lua_script_start ptp_saved_alt_state=0 script=serialize_r = fu      - initial script for remote_shoot start
00108630: DBG:enter_alt
00108620: DBG:gui_set_mode gui_mode_alt=1
00108660: DBG:lua_script_finish ptp_saved_alt_state=0                  - initial script end
00108660: DBG:exit_alt
00108660: DBG:gui_set_mode gui_mode_alt=0
00108690: DBG:lua_script_start ptp_saved_alt_state=0 script=focus={ mode_na   - rs_shoot script start
00108690: DBG:enter_alt
00108680: DBG:gui_set_mode gui_mode_alt=1

… camera events

00109830: DBG:lua_script_finish ptp_saved_alt_state=0                  - rs_shoot script end
00109830: DBG:exit_alt
00109830: DBG:gui_set_mode gui_mode_alt=0

… more camera events

00110590: DBG:lua_script_start ptp_saved_alt_state=0 script=function rs_clea      - final script start
00110590: DBG:enter_alt
00110580: DBG:gui_set_mode gui_mode_alt=1
00110610: DBG:lua_script_finish ptp_saved_alt_state=0                  - final script end
00110610: DBG:exit_alt
00110610: DBG:gui_set_mode gui_mode_alt=0

This is the call logic for a failed run:

Code: [Select]

00085570: DBG:lua_script_start ptp_saved_alt_state=0 script=serialize_r = fu
00085570: DBG:enter_alt
00085560: DBG:gui_set_mode gui_mode_alt=1
00085600: DBG:lua_script_finish ptp_saved_alt_state=0
00085600: DBG:exit_alt

00085620: DBG:lua_script_start ptp_saved_alt_state=1 script=focus={ mode_na      - rs_shoot - called before GUI has reset gu_mode_alt from previous exit_alt !!!
00085600: DBG:gui_set_mode gui_mode_alt=0                           - !!!! out of order !!!
00090670: DBG:lua_script_finish ptp_saved_alt_state=1

00106140: DBG:lua_script_start ptp_saved_alt_state=0 script=function rs_clea
00106140: DBG:enter_alt
00106120: DBG:gui_set_mode gui_mode_alt=1
00106160: DBG:lua_script_finish ptp_saved_alt_state=0
00106160: DBG:exit_alt
00106160: DBG:gui_set_mode gui_mode_alt=0

In this failed case the second script starts before the GUI code has reset the gui_mode_alt flag so it does not call enter_alt and the key presses get ignored.
The weird thing is the timestamps are out of order in the log.

Having the script start logic dependent on a flag set in another task is a bit dodgy, perhaps the speed of the G7X2 or having dual cores is exposing this where it was not seen previously.

Phil.

Logged

CHDK ports:
sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
g12 (1.00c, 1.00e, 1.00f & 1.00g)
sx130is (1.01d & 1.01f)
ixus310hs (1.00a & 1.01a)
sx40hs (1.00d, 1.00g & 1.00i)
g1x (1.00e, 1.00f & 1.00g)
g5x (1.00c, 1.01a, 1.01b)
g7x2 (1.01a, 1.01b, 1.10b)

philmoz

3450

Re: Issue with intermittent remoteshoot behaviour on G7X2

« Reply #1 on: 24 / October / 2020, 05:15:39 »

For review - patch to fix the above above on the G7X2.

Does not appear to cause any issues on other cameras - although I have not done extensive testing.

Phil.

remote_shoot_timeout.patch (2.15 kB - downloaded 21 times.)

Logged

CHDK ports:
sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
g12 (1.00c, 1.00e, 1.00f & 1.00g)
sx130is (1.01d & 1.01f)
ixus310hs (1.00a & 1.01a)
sx40hs (1.00d, 1.00g & 1.00i)
g1x (1.00e, 1.00f & 1.00g)
g5x (1.00c, 1.01a, 1.01b)
g7x2 (1.01a, 1.01b, 1.10b)

reyalp

14117

Re: Issue with intermittent remoteshoot behaviour on G7X2

« Reply #2 on: 25 / October / 2020, 22:01:00 »

Thanks for this.

I'm a little bit wary of adding yet another variable to track "alt" state, but it may be the most straightforward way to deal with it.

Anyway, I spent some time trying to understand the current state of affairs, and ran into another bit of (probably unrelated to your issue) weirdness in this area:
Note this is without the patch, on elph180

Running a chdkptp script which peeks the relevant values, camera not in alt:

Code: [Select]

kbd_blocked:1
camera_info.state.gui_mode:3 (GUI_MODE_SCRIPT)
camera_info.state.gui_mode_none:0
camera_info.state.gui_mode_alt:0

With cam in alt, set manually on the camera before running

Code: [Select]

kbd_blocked:1
camera_info.state.gui_mode:1 (GUI_MODE_ALT)
camera_info.state.gui_mode_none:0
camera_info.state.gui_mode_alt:1

The values are the same with a 500ms sleep before peeking, so it's not just a matter of spytask not updating state yet.

In other words, when the camera is already in "alt", running a PTP script doesn't go to GUI_MODE_SCRIPT, instead, it stays in GUI_MODE_ALT, which is not actually the same. This can be verified by running a long running script like

Code: [Select]

 =for i=1,1000 do sleep(10) end

and interrupting it with the shutter. If the camera was not in alt, you get *interrupted*. If it was, you get the default script, and likely memory corruption, because it doesn't kill / clean up the running script.

While this doesn't seem directly connected to your issue, in the first case (camera not in alt at PTP call), it seems like a second script run before spytask responded to the exit_alt should see camera_info.state.gui_mode_alt == 0, since it would still be in script mode. I could very easily be missing something though

It might be possible for gui_activate_alt_mode to run between when lua_script_start finishes and when script_stack_start sets camera_info.state.state_kbd_script_run

script_end can also set the gui handler directly, but I think that only happens in the GUI case.

Logged

Don't forget what the H stands for.

philmoz

3450

Re: Issue with intermittent remoteshoot behaviour on G7X2

« Reply #3 on: 26 / October / 2020, 17:23:11 »

Quote from: reyalp on 25 / October / 2020, 22:01:00

I'm a little bit wary of adding yet another variable to track "alt" state, but it may be the most straightforward way to deal with it.

I tried a few alternatives; but this seemed to be the safest way to mimic the existing behaviour.

Quote

Anyway, I spent some time trying to understand the current state of affairs, and ran into another bit of (probably unrelated to your issue) weirdness in this area:

In other words, when the camera is already in "alt", running a PTP script doesn't go to GUI_MODE_SCRIPT, instead, it stays in GUI_MODE_ALT, which is not actually the same. This can be verified by running a long running script like
Code: [Select]
=for i=1,1000 do sleep(10) endand interrupting it with the shutter. If the camera was not in alt, you get *interrupted*. If it was, you get the default script, and likely memory corruption, because it doesn't kill / clean up the running script.

This would only seem to be an issue when a script is run from chdkptp and the camera is already in ALT mode.

Running scripts in ALT mode by pressing the shutter button looks to be safe because script_start_gui and script_end functions set the gui_mode to GUI_MODE_SCRIPT and restore it.

Perhaps start_ptp_script needs to set old_gui_handler like script_start_gui does.
There are also other things that script_start_gui does that start_ptp_script does not do.

Phil.

« Last Edit: 26 / October / 2020, 17:25:14 by philmoz »

Logged

CHDK ports:
sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
g12 (1.00c, 1.00e, 1.00f & 1.00g)
sx130is (1.01d & 1.01f)
ixus310hs (1.00a & 1.01a)
sx40hs (1.00d, 1.00g & 1.00i)
g1x (1.00e, 1.00f & 1.00g)
g5x (1.00c, 1.01a, 1.01b)
g7x2 (1.01a, 1.01b, 1.10b)

philmoz

3450

Re: Issue with intermittent remoteshoot behaviour on G7X2

« Reply #4 on: 25 / November / 2020, 20:48:55 »

After discussing on IRC with reyalp it turns out the real issue is timing when a script starts from chdkptp.
On a dual-core camera the gui task can call gui_activate_alt_mode before the script initialisation has finished resulting in the wrong mode handler being set up.

Attached is a new patch that (hopefully) should fix this without changing the behaviour on single-core cameras.

EDIT: Patch updated with change suggested by reyalp.

Phil.

remote_shoot_timeout_v3.patch (4.04 kB - downloaded 16 times.)

« Last Edit: 26 / November / 2020, 00:05:26 by philmoz »

Logged

CHDK ports:
sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
g12 (1.00c, 1.00e, 1.00f & 1.00g)
sx130is (1.01d & 1.01f)
ixus310hs (1.00a & 1.01a)
sx40hs (1.00d, 1.00g & 1.00i)
g1x (1.00e, 1.00f & 1.00g)
g5x (1.00c, 1.01a, 1.01b)
g7x2 (1.01a, 1.01b, 1.10b)

reyalp

14117

Re: Issue with intermittent remoteshoot behaviour on G7X2

« Reply #5 on: 09 / December / 2020, 22:35:05 »

Quote from: reyalp on 25 / October / 2020, 22:01:00

In other words, when the camera is already in "alt", running a PTP script doesn't go to GUI_MODE_SCRIPT, instead, it stays in GUI_MODE_ALT, which is not actually the same. This can be verified by running a long running script like
Code: [Select]
=for i=1,1000 do sleep(10) endand interrupting it with the shutter. If the camera was not in alt, you get *interrupted*. If it was, you get the default script, and likely memory corruption, because it doesn't kill / clean up the running script.

After Phil checked in the patch in the post above, I attempted to clean this up in r5669.
ptp script now unconditionally sets to alt + script gui handler on start, and on exit, either exits alt, or returns to regular alt mode. I moved this logic so it also applies to error and key interrupt. Previously, error would leave the script GUI handler running, meaning the camera would appear to be in alt mode, but the menus wouldn't work.

A slight downside is if the camera wasn't in alt before the script started, the error won't be visible on the screen. However, in PTP you should hopefully get it in the client.

I thought about trying to uses the old_gui_handler logic in script.c script_end, but it would be hard to integrate with the saved_alt_state logic (I guess we could have a function to set it), and I'm not sure you'd ever want to got a GUI handler that wasn't alt or none.

Logged

Don't forget what the H stands for.