Script sleep oddity - page 2 - General Discussion and Assistance - CHDK Forum
« previous next »
Pages: 1 [2] 3 4 5 6   Go Down

Script sleep oddity

  • 57 Replies
  • 21271 Views
*

Offline reyalp

  • ******
  • 14111
Re: Script sleep oddity
« Reply #10 on: 13 / January / 2013, 18:54:36 »
Advertisements
shoot() seems to regularly miss shots on both my cameras with this patch.

This appears to be directly caused by the reduced implicit delay in the key press functions.
Code: [Select]
con 3> =c=get_exp_count();shoot();return get_exp_count()-c
4:return:0
con 7> =c=get_exp_count();press('shoot_half'); repeat sleep(10) until get_shooting(); sleep(100) click('shoot_full') repeat sleep(10) until not get_shooting() ;return get_exp_count()-c;
8:return:0
con 11> =c=get_exp_count();press('shoot_half'); repeat sleep(10) until get_shooting(); press('shoot_full') release('shoot_full'); repeat sleep(10) until not get_shooting() ;return get_exp_count()-c;
12:return:1
This isn't directly related to shooting, it applies to other clicks, e.g. click('menu') no longer reliably brings up the menu, while =press('menu');release('menu') does.

Patched build timing
Code: [Select]
con 14> =t=get_tick_count();click('shoot_full');return get_tick_count()-t
15:return:50
con 15> =t=get_tick_count();press('shoot_full');release('shoot_full');return get_tick_count()-t
16:return:60
con 16> =t=get_tick_count();press('set');return get_tick_count()-t
17:return:30

svn trunk
Code: [Select]
con> =t=get_tick_count();click('shoot_full');return get_tick_count()-t
1:return:90
con 1> =t=get_tick_count();press('shoot_full');release('shoot_full');return get_tick_count()-t
2:return:100
con> =t=get_tick_count();press('set');return get_tick_count()-t
1:return:50

trunk shooting works as expected:
Code: [Select]
con 4> =c=get_exp_count();shoot();return get_exp_count()-c
5:return:1
con 6> =c=get_exp_count();press('shoot_half'); repeat sleep(10) until get_shooting(); sleep(100) click('shoot_full') repeat sleep(10) until not get_shooting() ;return get_exp_count()-c;
7:return:1
Logged
Don't forget what the H stands for.
*

Offline reyalp

  • ******
  • 14111
Re: Script sleep oddity
« Reply #11 on: 13 / January / 2013, 19:49:44 »
Quote
Quote the min sleep duration for uBasic is 20msec - not sure why this is the case (Lua is 10msec).
Unless you've adjusted set_yield, ubasic probably takes 'extra' time because the default scheduling is 1 statement per kbd_task iteration.

This script gives the expected result, 20ms for the first and 10 for the second.
Code: [Select]
t=get_tick_count
sleep 10
print "time ", get_tick_count - t

set_yield 100 100
t=get_tick_count
sleep 10
print "time ", get_tick_count - t
Logged
Don't forget what the H stands for.
*

Offline philmoz

  • *****
  • 3450
    • Photos
Re: Script sleep oddity
« Reply #12 on: 13 / January / 2013, 20:00:04 »
Quote from: reyalp on 13 / January / 2013, 18:54:36
shoot() seems to regularly miss shots on both my cameras with this patch.

This appears to be directly caused by the reduced implicit delay in the key press functions.
Code: [Select]
con 3> =c=get_exp_count();shoot();return get_exp_count()-c
4:return:0
con 7> =c=get_exp_count();press('shoot_half'); repeat sleep(10) until get_shooting(); sleep(100) click('shoot_full') repeat sleep(10) until not get_shooting() ;return get_exp_count()-c;
8:return:0
con 11> =c=get_exp_count();press('shoot_half'); repeat sleep(10) until get_shooting(); press('shoot_full') release('shoot_full'); repeat sleep(10) until not get_shooting() ;return get_exp_count()-c;
12:return:1
This isn't directly related to shooting, it applies to other clicks, e.g. click('menu') no longer reliably brings up the menu, while =press('menu');release('menu') does.

Patched build timing
Code: [Select]
con 14> =t=get_tick_count();click('shoot_full');return get_tick_count()-t
15:return:50
con 15> =t=get_tick_count();press('shoot_full');release('shoot_full');return get_tick_count()-t
16:return:60
con 16> =t=get_tick_count();press('set');return get_tick_count()-t
17:return:30

svn trunk
Code: [Select]
con> =t=get_tick_count();click('shoot_full');return get_tick_count()-t
1:return:90
con 1> =t=get_tick_count();press('shoot_full');release('shoot_full');return get_tick_count()-t
2:return:100
con> =t=get_tick_count();press('set');return get_tick_count()-t
1:return:50

trunk shooting works as expected:
Code: [Select]
con 4> =c=get_exp_count();shoot();return get_exp_count()-c
5:return:1
con 6> =c=get_exp_count();press('shoot_half'); repeat sleep(10) until get_shooting(); sleep(100) click('shoot_full') repeat sleep(10) until not get_shooting() ;return get_exp_count()-c;
7:return:1


That's what I was afraid might happen (although I haven't seen it on my cameras yet).

Poking too hard at this house of cards is going to cause something to fail - so do we live with it, or fix the underlying system and deal with breakages as they are found?

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)
*

Offline reyalp

  • ******
  • 14111
Re: Script sleep oddity
« Reply #13 on: 13 / January / 2013, 22:05:43 »
Quote from: philmoz on 13 / January / 2013, 20:00:04
That's what I was afraid might happen (although I haven't seen it on my cameras yet).
I'd expect the ones that use CAM_KEY_CLICK_DELAY not to miss clicks (i expect the 150ms most of those use is overkill), but I'm a bit surprised G12 isn't affected.

Quote
Poking too hard at this house of cards is going to cause something to fail - so do we live with it, or fix the underlying system and deal with breakages as they are found?
I'm not averse to breakages if we can move the house of cards toward something better. Less so if we are just re-arranging them...

Some thoughts:
We could make the change only impact scripted sleep rather than in action_push_delay
We could pad the existing keyboard waits, e.g. add 20ms to CAM_KEY_PRESS/RELEASE_DELAY

At a minimum, click() needs to holds a key down long enough to reliably be recognized by the firmware as a click. The shoot_full in shoot() should do the same thing (plus whatever we come up with to deal with the issues lapser identified...)

Should press();release() have enough built in delay to count as a click? If we were starting fresh, I'd be tempted to say no, but given that it generally has up to now it probably should.
Logged
Don't forget what the H stands for.
*

Offline lapser

  • *****
  • 1093
Re: Script sleep oddity
« Reply #14 on: 14 / January / 2013, 00:45:16 »
Quote from: reyalp on 05 / February / 2012, 17:54:08
edit:
Of course, I can't initialize the end tick on push, because other stuff might be pushed after that. It needs to happen when the delay comes to the top of the stack. One way to deal with this would be to have a way to process the stack again right away, instead of waiting for the next kbd_task iteration to come around.
I think this IS what you want to do for a script sleep(t) call.  In this case, there is only 1 delay, with nothing else after it.

Code: [Select]
void action_push_tsleep(long msec)
{
    action_push(msec+get_tick_count());
    action_push(AS_TSLEEP);
}

    case AS_TSLEEP:
        if(get_tick_count()>=action_get_prev(2))
        {
            action_pop();
            action_pop();
        }
        break;

static int luaCB_sleep( lua_State* L )
{
  action_push_tsleep( luaL_checknumber( L, 1 ) );
  return lua_yield( L, 0 );
}

//also change uBasic call
Logged
EOS-M3_120f / SX50_100b / SX260_101a / G1X_100g / D20_100b
https://www.youtube.com/user/DrLapser/videos
*

Offline lapser

  • *****
  • 1093
Re: Script sleep oddity
« Reply #15 on: 14 / January / 2013, 01:14:15 »
The current AS_SHOOT does a press and immediate release of KEY_SHOOT_FULL, without the click delay. If you shorten delay after the key press, this could cause it to miss shots. The fact that shoot() works most of the time on all cameras suggests that the 150 msec click delay is longer than needed.

Another problem with msec delays is that sometimes the camera gets really busy and more than 10 msec passes between action stack iterations. So when adding a delay for the camera to recognize a key press or release, it would be better to use a delay in action stack cycles, rather than msec. A key press delay of 3 cycles would probably eliminated the need for a click delay too.

Code: [Select]
void action_push_delay_cycles(long cycles)
{
    action_push(cycles);
    action_push(AS_WAIT_CYCLES);
}

    case AS_WAIT_CYCLES: //wait minimum # of cycles through action stack
        skey=action_get_prev(2); //# of cycles.. using skey as temp
        action_pop();         
        action_pop();
        if(skey>0)
        {
          action_push(skey-1);   
          action_push(AS_WAIT_CYCLES);
        }
        //script_console_add_line("wait cycle");//debug . . ..
        break;
By delaying in cycles instead of msec, you might be able to eliminate all the camera specific time delays and replace them with a camera independent delay of a certain number of cycles.

I noticed that it prints "wait cycle" one more time than expected. It would be helpful to print the tick count for every cycle (on my to do list).
Logged
EOS-M3_120f / SX50_100b / SX260_101a / G1X_100g / D20_100b
https://www.youtube.com/user/DrLapser/videos
*

Offline reyalp

  • ******
  • 14111
Re: Script sleep oddity
« Reply #16 on: 14 / January / 2013, 02:15:32 »
Quote from: lapser on 14 / January / 2013, 01:14:15
Another problem with msec delays is that sometimes the camera gets really busy and more than 10 msec passes between action stack iterations. So when adding a delay for the camera to recognize a key press or release, it would be better to use a delay in action stack cycles, rather than msec.
shooting is a special case, because there are various conditions that need to be met to successfully start a shot. I'm not convinced that this applies to the camera recognizing key presses in general.
Logged
Don't forget what the H stands for.
*

Offline philmoz

  • *****
  • 3450
    • Photos
Re: Script sleep oddity
« Reply #17 on: 14 / January / 2013, 04:39:49 »
Quote from: lapser on 14 / January / 2013, 00:45:16
Quote from: reyalp on 05 / February / 2012, 17:54:08
edit:
Of course, I can't initialize the end tick on push, because other stuff might be pushed after that. It needs to happen when the delay comes to the top of the stack. One way to deal with this would be to have a way to process the stack again right away, instead of waiting for the next kbd_task iteration to come around.
I think this IS what you want to do for a script sleep(t) call.  In this case, there is only 1 delay, with nothing else after it.

Code: [Select]
void action_push_tsleep(long msec)
{
    action_push(msec+get_tick_count());
    action_push(AS_TSLEEP);
}

    case AS_TSLEEP:
        if(get_tick_count()>=action_get_prev(2))
        {
            action_pop();
            action_pop();
        }
        break;

static int luaCB_sleep( lua_State* L )
{
  action_push_tsleep( luaL_checknumber( L, 1 ) );
  return lua_yield( L, 0 );
}

//also change uBasic call


A custom sleep timer routine for scripts may well be needed (as reyalp suggested); but this version suffers from the same problem as the current implementation - namely the actual time sleeping is always larger than the requested time (in this case 10msec). This is due to the overhead of yielding the script, and processing the action stack.

So it's better than the current version; but still not as accurate as it could be.

It also misses the current functionality where you can call sleep(-1) to wait indefinitely (well 24 hours anyway).

This code for the current trunk version should work for Lua:
Code: [Select]
// Process a sleep function from the stack
static void action_stack_AS_LUA_SLEEP()
{
    if (get_tick_count() >= action_top(2))
    {
        action_pop_func();
        action_pop();
    }
}

static int luaCB_sleep( lua_State* L )
{
    int delay = luaL_checknumber( L, 1 );

    /* delay of -1 signals indefinite (actually 1 day) delay */
    if (delay == -1)
        delay = 86400000;
    else
        delay = (delay + 5) / 10) * 10;

    if (delay > 10)
    {
        action_push(delay-10 + get_tick_count());
        action_push_func(action_stack_AS_LUA_SLEEP);
    }

    return lua_yield( L, 0 );
}

This code rounds the sleep value up or down to the nearest 10msec boundary. So a value of 11-14 sleeps for 10, while 15-18 sleeps for 20msec. It might be better to always round up to the next 10msec interval.

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)
*

Offline lapser

  • *****
  • 1093
Re: Script sleep oddity
« Reply #18 on: 14 / January / 2013, 11:45:43 »
Quote from: philmoz on 14 / January / 2013, 04:39:49
This code rounds the sleep value up or down to the nearest 10msec boundary. So a value of 11-14 sleeps for 10, while 15-18 sleeps for 20msec. It might be better to always round up to the next 10msec interval.
Nice work Phil. I agree it would be better to round up, making it a sleep_at_least(msec) function. Processing the action stack rounds up for you, so you don't need a calculation.

Since it works for uBasic too, it would be more accurate to call it AS_SCRIPT_SLEEP in the action_stack_standard function:
Code: [Select]
case AS_SCRIPT_SLEEP:
    if (get_tick_count() >= action_get_prev(2))
    {
        action_pop();
        action_pop();
    }
    break:

void action_push_script_sleep(long delay)
{
    /* delay of -1 signals indefinite (actually 1 day) delay */
    if (delay == -1)
        delay = 86400000;
    if (delay > 10)
    {
        //delay=(delay/10)*10; //I don't think this is needed.
        action_push(delay-10 + get_tick_count());
        action_push(AS_SCRIPT_SLEEP);
    }
}

static int luaCB_sleep( lua_State* L )
{
  action_push_script_sleep( luaL_checknumber( L, 1 ) );
  return lua_yield( L, 0 );
}

//also change uBasic call to
static void
sleep_statement(void)
{
  int val;
  accept(TOKENIZER_SLEEP);
  val = expr();
  action_push_script_sleep(val); //**********changed
  flag_yield=1;
  DEBUG_PRINTF("End of sleep\n");
  accept_cr();
}
Also, I don't see action_push_func(), etc.,  defiined anywhere in the 1.2 build. Where do they come from?
Logged
EOS-M3_120f / SX50_100b / SX260_101a / G1X_100g / D20_100b
https://www.youtube.com/user/DrLapser/videos
*

Offline philmoz

  • *****
  • 3450
    • Photos
Re: Script sleep oddity
« Reply #19 on: 14 / January / 2013, 14:34:29 »
Quote from: lapser on 14 / January / 2013, 11:45:43
Also, I don't see action_push_func(), etc.,  defiined anywhere in the 1.2 build. Where do they come from?

You need to update your source from SVN.
The trunk version was merged from my reorg branch a week ago which includes a rework of the action stack code.

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)
Pages: 1 [2] 3 4 5 6   Go Up
« previous next »
 

Related Topics
SimplePortal 2.3.6 © 2008-2014, SimplePortal