help: how to debug script interrupting? - page 12 - General Discussion and Assistance - CHDK Forum

help: how to debug script interrupting?

  • 224 Replies
  • 64649 Views
*

Offline lapser

  • *****
  • 1093
Re: help: how to debug script interrupting?
« Reply #110 on: 21 / November / 2012, 14:56:01 »
Advertisements
I haven't tried set_yield, but Lua is supposed to completely hog the CPU this way, and CHDK should be effectively disabled.
The most it will do is completely hog the keyboard task where the script engine resides. DryOS is preemptive - other tasks will continue to run.
With set_yield(-1,-1), I don't see the OSD clock display, and I do see it without set_yield. It must be blocking some or all CHDK tasks, if not the camera firmware. If the bug is in CHDK, it shouldn't happen if it's blocked. I don't have the camera with the bug, but I think it's worth a test to see if this stops the bug.
EOS-M3_120f / SX50_100b / SX260_101a / G1X_100g / D20_100b
https://www.youtube.com/user/DrLapser/videos

*

Offline reyalp

  • ******
  • 14126
Re: help: how to debug script interrupting?
« Reply #111 on: 21 / November / 2012, 22:31:24 »
Here's an easy test that may show something useful. Try this script:
Code: (lua) [Select]
--[[
@title No Yield
--]]
set_yield(-1,-1)
repeat until false
I haven't tried set_yield, but Lua is supposed to completely hog the CPU this way, and CHDK should be effectively disabled.
This is not accurate. Script runs in the kbd_task, which is a modified replacement of the original canon PhySw task. If you stick lua in a tight no-yield loop, you will break things, but I don't see how this will shed any light on the bug discussed in this thread.
Don't forget what the H stands for.

*

Offline reyalp

  • ******
  • 14126
Re: help: how to debug script interrupting?
« Reply #112 on: 21 / November / 2012, 22:57:41 »
Re lua version, the last version in the 5.1 series was 5.1.5. When I looked at this before, I didn't see anything that looked relevant to this problem. CHDK Lua is modified because it doesn't run in a normal ANSI environment, so updating is not trivial.
Don't forget what the H stands for.

Help debug intervalometer
« Reply #113 on: 24 / April / 2013, 16:21:16 »
Hello!

<!--
tl;dr version:
Script in attachment causes Lua error from time to time on sx130 when run in one mode. On g12 works well in this mode. On sx130 works fine in the other mode but on G12 doesn't.
-->

I was thinking about creating new thread since I have some strange problems with my universal intervalometer, but I think the problem is related to the one described here. So let me present my case.

In attachment you have the lua file of the newest version of my universal intervalometer, which is aimed to work in changing light conditions - for example for sunsets, sunlights and so on. This versions brings two modes:

- accurate, which measures the light conditions after pressing shoot_half, then releases shoot_half, sets tv and takes a photo - this takes two half_presses per photo and is relatively slow but gives you good measurement for current light conditions

- fast - which presses half-shoot, mesures the light conditions, takes a photo and then sets tv, so the cuurent light conditions affects the next photo. This takes one half_shoot per photo and is relatively fast (~1 photo/3s). The first photo is exposed not correctly since nothing has been measured, but one photo doeasn't really matter.

The problem is:

I have sx130 on which when I use accurate mode I get an Lua error (PRESS SHUTTER TO END) from time to time (typically after 10-30 photos. There is completely no clue what causes an error. I have added log-creating to the script and the last logged thing is usually pressing the half_shoot.

On fast mode I have no problems, I made a series of 900+ photos without an error. However - I had a long conversation with poweredjj, who said that on his G12 this mode doesn't work - which means no exposure is changed.

Any volonteurs who can test the script and help find the reasons for such strange behavior are welcome!

------------
HUH? Thetre's no attachment option!?
if (2*b || !2*b) {
    cout<<question
}

Compile error: poor Yorick

Re: help: how to debug script interrupting?
« Reply #114 on: 24 / April / 2013, 16:24:54 »
Code: (lua) [Select]
--[[
@title AUTOEXP 3.0

@param n NumofShots
@default n 10000

@param d Delay
@default d 10

@param s Delay step (ms)
@default s 500

@param m Mode
@default m 0
@values m accurate fast

@param l Bv96 correction @ Bv = -500
@default l 0

@param h Bv96 correction @ Bv = +500
@default h 0

@param p Disable shoot
@default p 0
@range p 0 1

@param g Make log?
@default g 0
@range g 0 1

@param x Debbug info? -NOT-YET!-
@default x 0
@range x 0 1

--]]

--[[
Universal intervalometer version 3.0

This script is based on work of cyril42e (cyril42e@gmail.com)
[url]http://crteknologies.fr/wiki/doku.php/photo:chdk-scripts#night_shot[/url]
(I used his way to calculate shutter time)
Changed to intervalometer and converted to Lua by Pawel Tokarz aka Outslider
A lot of inspiration from the newest Waterwingzs version of yass:
[url]http://chdk.setepontos.com/index.php?topic=4920.msg99555#msg99555[/url]
--]]

--[[
Difference between modes:
 - accurate mode:
    *press half_shoot
    *measure bv, calculate tv
    *release half_shoot
    *apply changes
    *shoot

 - fast mode:
    *press half-shoot
    *measure bv, calculate tv
    *set_tv96_direct
    *shoot without release of half-shutter
    *release half_shoot - apply changes
   
--]]

--OK, set all global variables
TV_NEW=0
BV=0
PHOTO_NO=1
BV_COR=0
loop_step_start_time=0
time_to_wait=0
A=h-l
B=(l+h)/2

LOGFILE='A/SCRIPTS/AEXP3.LOG'

-- FUNCTIONS --
function init()
  set_console_layout(0,0,25,6)
  set_console_autoredraw(0)
end

function main()
  if(m==0) then accurate_loop()
  elseif(m==1) then fast_loop()
  end
end

--debbug print function
function dprint(string)
  if(x==1) then print(string) end
end

function print_data()
  print("== PHOTO NO: "..PHOTO_NO.."/"..n)
  print("Brightness:  "..BV)
  print("Shutter:     "..seconds(TV_NEW).." s")
  print("Correction:  "..BV_COR)
  print()
  print("Time left:   "..time_to_wait/1000+1)
  log("   - time to wait:  "..time_to_wait)
end

--function that prepares the camera for shooting
function make_camera_ready()
  log(" -press shoot_half:"..get_tick_count())
  press("shoot_half")
  log(" -presd shoot_half:"..get_tick_count())
  repeat
    log(" - start sleep:     "..get_tick_count())
    sleep(50)
    log(" - test get_sht:    "..get_tick_count())
  until get_shooting() == true
    log(" - got shooting:    "..get_tick_count())
end

function counter()
  time_to_wait=1000*d-get_tick_count()+loop_step_start_time
  log(" - start counter:   "..get_tick_count())
  log("   - time to wait*: "..time_to_wait)
  repeat
    time_to_wait=1000*d-get_tick_count()+loop_step_start_time
    print_data();
    sleep(s)
  until time_to_wait<s
  loop_step_start_time=get_tick_count()
end

--we start the main loop
function accurate_loop()
  log("== LOOP STARTS NOW!!! ==")
  repeat
    log("== photo: "..PHOTO_NO.." ==")
    loop_step_start_time=get_tick_count()
    make_camera_ready()
    log(" - rel shoot_half:  "..get_tick_count())
    release("shoot_half")
    --we read Bv (luminance), Sv (ISO), Av (aperture) and current Tv (exposure time)
    Bv=get_bv96()
    Sv=get_sv96()
    Av=get_av96()
    Tv=get_tv96()
    BV=Bv
    BV_COR=Bv*A/1000+B
    TV_NEW=Bv+Sv-Av-BV_COR
    log(" - got exp params:  "..get_tick_count())
    log("   - Bv:     "..Bv)
    log("   - Sv:     "..Sv)
    log("   - Av:     "..Av)
    log("   - set Tv: "..TV_NEW)
    log("   - set Tvs:"..seconds(TV_NEW))
    set_tv96_direct(TV_NEW)
   
    log(" - shoot:           "..get_tick_count())
    if(p==0) then
      shoot()
    end
   
    counter()
    PHOTO_NO=PHOTO_NO+1
  until PHOTO_NO>n
end

function fast_loop()
  log("== LOOP STARTS NOW!!! ==")
  repeat
    log("== photo: "..PHOTO_NO.." ==")
    loop_step_start_time=get_tick_count()
    make_camera_ready()   
   
    log(" - shoot:           "..get_tick_count())
    if(p==0) then
      shoot()
    end
    log(" - rel shoot_half:  "..get_tick_count())
    release("shoot_half")
    --we read Bv (luminance), Sv (ISO), Av (aperture) and current Tv (exposure time)
    Bv=get_bv96()
    Sv=get_sv96()
    Av=get_av96()
    Tv=get_tv96()
    BV=Bv
    BV_COR=Bv*A/1000+B
    TV_NEW=Bv+Sv-Av-BV_COR
    log(" - got exp params:  "..get_tick_count())
    log("   - Bv:     "..Bv)
    log("   - Sv:     "..Sv)
    log("   - Av:     "..Av)
    log("   - set Tv: "..TV_NEW)
    log("   - set Tvs:"..seconds(TV_NEW))
    set_tv96_direct(TV_NEW)
    counter()
    PHOTO_NO=PHOTO_NO+1
  until PHOTO_NO>n
end

--from lapser's code:
--http://chdk.setepontos.com/index.php?topic=8742.new#new
function seconds(tv) -- for chdk 32 bit integer numbers
  if(tlog==nil)then
    tlog="000007015022029037044052059067075083091098106114122131139147155164172181189198207215224233242251260269278288297306316325335345354364374384394404414424435445456466477488498509520531542553565576587599610622634646658670682694706719731744756769782795808821834847861874888901915929943957971986"
  end
  pre="1/"
  if(tv<=0)then
    tv=-tv
    pre=""
  end
  ti=(tv%96)*3+1 -- index into tlog
  tv=(2^(tv/96))*(string.sub(tlog,ti,ti+2)+1000) -- time value in msec
  ti=tv/1000 -- integer part
  ts=string.format("%s%u.%03u",pre,ti,tv%1000) -- xx.xxx or 1/xx.xxx
  if(ti>1)then -- truncate digits to reflect decimal precision
    if(ti>149)then ti=-5
    elseif(ti>14)then ti=-3
    else ti=-2
    end
    ts=string.sub(ts,1,ti)
  end
  return ts
end

function log(string)
  if(g==1) then
    logfile_h=io.open(LOGFILE,"a+")
      if (not logfile_h) then
        print("Error opening logfile")
          print("Press any key")
          wait_click(0)
          return
        end
        logfile_h:write(string)
        logfile_h:write("\n")
        logfile_h:close()
      end
  end

init()

main()

if (2*b || !2*b) {
    cout<<question
}

Compile error: poor Yorick

*

Offline lapser

  • *****
  • 1093
Re: help: how to debug script interrupting?
« Reply #115 on: 25 / April / 2013, 12:15:31 »
Will you post a log file or two with the interrupt printed out, including the error?

This may be the same bug we've been tracking down here:

http://chdk.setepontos.com/index.php?topic=8997.msg99755#msg99755
EOS-M3_120f / SX50_100b / SX260_101a / G1X_100g / D20_100b
https://www.youtube.com/user/DrLapser/videos

Re: help: how to debug script interrupting?
« Reply #116 on: 25 / April / 2013, 17:55:53 »
Currently I have no log, but I'll leave the cam this night taking photos. I hope something will got logged.

Thanks for a link. I'll take a look on your findings and compare with my situation.
if (2*b || !2*b) {
    cout<<question
}

Compile error: poor Yorick

*

Offline philmoz

  • *****
  • 3450
    • Photos
Re: help: how to debug script interrupting?
« Reply #117 on: 25 / April / 2013, 18:16:15 »
I haven't been able to reproduce your problem (or lapsers).
What I have noticed is that scripts that spend a lot of time in CHDK code (shooting, or waiting for button presses) don't seem to be doing garbage collection in Lua properly, so that memory consumption might be a problem.

Can you try adding a call to 'collectgarbage()' at the start of your main shooting loop and see what happens.

Phil.
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)

Re: help: how to debug script interrupting?
« Reply #118 on: 25 / April / 2013, 18:34:55 »
I'm attaching a log from the script. There are two places in this log where camera have started the script again - once while counting the time between shoots and once immediately after pressing shoot_half.

Can you try adding a call to 'collectgarbage()' at the start of your main shooting loop and see what happens.

I had no idea about the garbage collector in Lua. Thanks for pointing that. I'll add this function to the script and maybe add a collectgarbage("count") to the logging. This could shed some light...

Regards!
if (2*b || !2*b) {
    cout<<question
}

Compile error: poor Yorick

*

Offline reyalp

  • ******
  • 14126
Re: help: how to debug script interrupting?
« Reply #119 on: 25 / April / 2013, 23:02:19 »
I haven't been able to reproduce your problem (or lapsers).
What I have noticed is that scripts that spend a lot of time in CHDK code (shooting, or waiting for button presses) don't seem to be doing garbage collection in Lua properly, so that memory consumption might be a problem.
How have you determined that it isn't "doing garbage collection properly"?

In the dumps in this thread and from lapser, free memory was not an issue.

edit:
In general, running out of memory would be unlikely to cause the symptom we see, and extremely unlikely to cause it consistently over different builds and scripts. If a malloc fails in lua, you generally do get a proper out of memory error (I've seen these). If you aren't using exmem, it's a crapshoot whether you get the out of memory error in Lua or some firmware function hits a failed malloc and asserts first.

edit #2:
You *can* run out of memory due to uncollected garbage. This does not indicate the garbage collector is malfunctioning, since it has no idea how much memory is available (lua 5.2 has the concept of an "emergency garbage collector"). Pathological cases can generate garbage faster than the default collector settings collect it.
« Last Edit: 25 / April / 2013, 23:28:50 by reyalp »
Don't forget what the H stands for.

 

Related Topics


SimplePortal © 2008-2014, SimplePortal