Lua Scripting (lua.mo)

Started by dmilligan, March 29, 2015, 04:44:07 AM

Previous topic - Next topic

0 Members and 1 Guest are viewing this topic.

lojzik

some test on magiclantern-lua_fix.2017Dec19.70D112
-


- luatest.log: https://drive.google.com/file/d/1kZ870XWBPZXDPBjCNO4v2x6_-mNJbQcj/view?usp=sharing
I recall some assertion error in "console" on display during api_test that is not in log. Is it possible?
- build without selftest.mo


70D.112

a1ex

Will check; not sure if the assertions are saved in the log file, but you should be able to write down the line number (which can be looked up in api_test.lua to find exactly what went wrong). Running this test from default ML settings might help (no other modules loaded or settings changed), although it should tolerate a few variations.

New lua_fix build available, with selftest.mo for 70D and temperature reporting from esas (otherwise identical).

lojzik

magiclantern-lua_fix.2017Dec23.70D112 tests:

logs: https://drive.google.com/drive/folders/1pF8Zv15SLbEOjOE5zEe5z3btghO0IQll?usp=sharing
assertion failed on api_test.lua:464
70D.112

a1ex

Tried to reproduce this snippet in QEMU (emulation is not yet good enough to run all the tests), but I've got assert at line 424 instead. Commented it out and the remaining menu tests passed.

In the selftest.log there are a few failed tests, at autofocus routines. Did the camera have something to focus on?

lojzik

I have camera on tripod and with focus is not problem and I have focus beep during failed focus test

sorry, my mistake, I have error on 424 too. If I comment 424, I get assert error on 1208.


70D.112

a1ex

The second error is autofocus related (just like the failed stub tests).

Does it help if you disable continuous AF and manually focus using half-shutter?

lojzik

I don't understand. I have on-shot AF and camera is focused before tests (I test, If focus is possible before tests).
70D.112

a1ex

All Canon DSLRs I've tried will wait for you to press the shutter button halfway in order to focus; to my knowledge, the 70D will autofocus continuously (although I've never tried that, so maybe the assumptions I'm using in ML about autofocus may not be valid on this camera).

I hope it's clear from the context (e.g. api_test.lua messages near the error) that we are talking about autofocus in LiveView.

So... if you configure AF in LiveView to behave like on the older models, do these tests pass?

lojzik

luatest - now it's ok, I exceeded timeout for one user interaction, sorry.
stubs test - I have FlexiZone - single, in movie mode, if I disable Servo AF before tests, Servo AF is enabled by itself
70D.112

Walter Schulz

Quote from: a1ex on December 16, 2017, 01:36:42 AM
Call for testers - as lately I've been hunting various bugs on this branch, and noticed some of the changes introduced model-specific issues (for example, api_test.lua was failing on 60D on one of the earliest tests).

For every single camera model available on the Experiments page (lua_fix build), please run:

- api_test.lua (upload the log)
- selftest.mo -> stubs tests (upload the log)
- bench.mo -> memory benchmarks (upload the screenshot)
- overall sanity check (for example, if you decide to take this build out and use it for a couple of hours, please report back)

650D preliminary
====
http://filehorst.de/d/cbiJgEiI

Used a rather slow card with about 20 MByte/s write and >45 MByte/s read.
Odd observation:
With Global Draw OFF read performance dropped from 43.x to about 38.x. Not what I expected.
No time for field test right now.


esas

Have beent testing on 70D and 650D. Unfortunately battery died on 70D and can't charge before christmas is over.

On both 70D and 650D it fails focus tests. Best case has been 3 fails on 70D, normally 10-15 fails on both 650D or 70D.

On luatest it fails at 424 on both cameraes. On 650D it also failed once  on 270 (on first attempt, second failed at 424).

Results from 650D:




.



===============================================================================
ML/SCRIPTS/api_test.lua - 2017-12-24 16:43:30
===============================================================================

Strict mode tests...
Strict mode tests passed.

Generic tests...
arg = table:
  [0] = "api_test.lua"
camera = table:
  shutter = table:
    raw = 96
    apex = 5
    ms = 31
    value = 0.03125
  aperture = table:
    raw = 40
    apex = 4
    value = 4
    min = table:
      raw = 31
      apex = 2.875
      value = 2.7
    max = table:
      raw = 87
      apex = 9.874999
      value = 30.6
  iso = table:
    raw = 104
    apex = 9
    value = 1600
  ec = table:
    raw = 0
    value = 0
  flash_ec = table:
    raw = 0
    value = 0
  kelvin = 5200
  mode = 3
  metering_mode = 4
  drive_mode = 0
  model = "Canon EOS 650D"
  model_short = "650D"
  firmware = "1.0.4"
  temperature = 151
  gui = table:
    menu = false
    play = false
    play_photo = false
    play_movie = false
    qr = false
    idle = true
  reboot = function: p
  bulb = function: p
  shoot = function: p
  burst = function: p
  wait = function: p
event = table:
  pre_shoot = nil
  post_shoot = nil
  shoot_task = nil
  seconds_clock = nil
  keypress = nil
  custom_picture_taking = nil
  intervalometer = nil
  config_save = nil
console = table:
  hide = function: p
  write = function: p
  clear = function: p
  show = function: p
lv = table:
  enabled = false
  paused = false
  running = false
  zoom = 1
  overlays = false
  pause = function: p
  start = function: p
  resume = function: p
  stop = function: p
  info = function: p
  wait = function: p
lens = table:
  name = "17-50mm"
  focal_length = 0
  focus_distance = 14080
  hyperfocal = 0
  dof_near = 0
  dof_far = 0
  af = true
  af_mode = 0
  autofocus = function: p
  focus = function: p
display = table:
  idle = nil
  height = 480
  width = 720
  rect = function: p
  clear = function: p
  screenshot = function: p
  off = function: p
  line = function: p
  draw = function: p
  pixel = function: p
  print = function: p
  on = function: p
  load = function: p
  notify_box = function: p
  circle = function: p
key = table:
  last = 10
  press = function: p
  wait = function: p
menu = table:
  visible = false
  open = function: p
  get = function: p
  block = function: p
  new = function: p
  close = function: p
  set = function: p
  select = function: p
movie = table:
  recording = false
  start = function: p
  stop = function: p
dryos = table:
  clock = 11
  ms_clock = 11384
  image_prefix = "IMG_"
  dcim_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "B:/DCIM/"
    path = "B:/DCIM/100CANON/"
  config_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "ML/"
    path = "ML/SETTINGS/"
  ml_card = table:
    cluster_size = 131072
    drive_letter = "B"
    file_number = 1854
    folder_number = 100
    free_space = 123521024
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  shooting_card = table:
    cluster_size = 131072
    drive_letter = "B"
    file_number = 1854
    folder_number = 100
    free_space = 123521024
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  date = table:
    yday = 358
    isdst = false
    sec = 31
    min = 43
    day = 24
    wday = 1
    month = 12
    hour = 16
    year = 2017
  directory = function: p
  call = function: p
  rename = function: p
  remove = function: p
interval = table:
  time = 10
  count = 0
  running = false
  stop = function: p
battery = table:
function not available on this camera
stack traceback:
[C]: in ?
[C]: in for iterator 'for iterator'
ML/SCRIPTS/LIB/logger.lua:125: in function 'logger.serialize'
ML/SCRIPTS/api_test.lua:36: in function <ML/SCRIPTS/api_test.lua:35>
[C]: in function 'globals.xpcall'
ML/SCRIPTS/api_test.lua:35: in function 'globals.print_table'
ML/SCRIPTS/api_test.lua:81: in function 'globals.generic_tests'
ML/SCRIPTS/api_test.lua:1338: in function 'globals.api_tests'
ML/SCRIPTS/api_test.lua:1364: in main chunktask = table:
  yield = function: p
  create = function: p
property = table:
Generic tests completed.

Module tests...
Testing file I/O...
Copy test: autoexec.bin -> tmp.bin
Copy test OK
Append test: tmp.txt
Append test OK
Rename test: apple.txt -> banana.txt
Rename test OK
Rename test: apple.txt -> ML/banana.txt
Rename test OK
File I/O tests completed.

Testing Canon GUI functions...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Pause LiveView...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Resume LiveView...
Pause LiveView...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...

===============================================================================
ML/SCRIPTS/api_test.lua - 2017-12-24 16:47:19
===============================================================================

Strict mode tests...
Strict mode tests passed.

Generic tests...
arg = table:
  [0] = "api_test.lua"
camera = table:
  shutter = table:
    raw = 96
    apex = 5
    ms = 31
    value = 0.03125
  aperture = table:
    raw = 40
    apex = 4
    value = 4
    min = table:
      raw = 31
      apex = 2.875
      value = 2.7
    max = table:
      raw = 87
      apex = 9.874999
      value = 30.6
  iso = table:
    raw = 104
    apex = 9
    value = 1600
  ec = table:
    raw = 0
    value = 0
  flash_ec = table:
    raw = 0
    value = 0
  kelvin = 5200
  mode = 3
  metering_mode = 4
  drive_mode = 0
  model = "Canon EOS 650D"
  model_short = "650D"
  firmware = "1.0.4"
  temperature = 154
  gui = table:
    menu = false
    play = false
    play_photo = false
    play_movie = false
    qr = false
    idle = true
  bulb = function: p
  reboot = function: p
  burst = function: p
  wait = function: p
  shoot = function: p
event = table:
  pre_shoot = nil
  post_shoot = nil
  shoot_task = nil
  seconds_clock = nil
  keypress = nil
  custom_picture_taking = nil
  intervalometer = nil
  config_save = nil
console = table:
  clear = function: p
  write = function: p
  show = function: p
  hide = function: p
lv = table:
  enabled = false
  paused = false
  running = false
  zoom = 1
  overlays = false
  resume = function: p
  pause = function: p
  info = function: p
  start = function: p
  wait = function: p
  stop = function: p
lens = table:
  name = "17-50mm"
  focal_length = 0
  focus_distance = 14080
  hyperfocal = 0
  dof_near = 0
  dof_far = 0
  af = true
  af_mode = 0
  autofocus = function: p
  focus = function: p
display = table:
  idle = nil
  height = 480
  width = 720
  load = function: p
  rect = function: p
  circle = function: p
  draw = function: p
  clear = function: p
  notify_box = function: p
  off = function: p
  line = function: p
  pixel = function: p
  on = function: p
  screenshot = function: p
  print = function: p
key = table:
  last = 10
  press = function: p
  wait = function: p
menu = table:
  visible = false
  block = function: p
  set = function: p
  new = function: p
  close = function: p
  select = function: p
  get = function: p
  open = function: p
movie = table:
  recording = false
  stop = function: p
  start = function: p
dryos = table:
  clock = 15
  ms_clock = 15208
  image_prefix = "IMG_"
  dcim_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "B:/DCIM/"
    path = "B:/DCIM/100CANON/"
  config_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "ML/"
    path = "ML/SETTINGS/"
  ml_card = table:
    cluster_size = 131072
    drive_letter = "B"
    file_number = 1854
    folder_number = 100
    free_space = 123519872
    type = "SD"
    path = "B:/"
    _card_ptr = userdata
  shooting_card = table:
    cluster_size = 131072
    drive_letter = "B"
    file_number = 1854
    folder_number = 100
    free_space = 123519872
    type = "SD"
    path = "B:/"
    _card_ptr = userdata
  date = table:
    day = 24
    month = 12
    sec = 20
    isdst = false
    hour = 16
    wday = 1
    yday = 358
    year = 2017
    min = 47
  directory = function: p
  rename = function: p
  remove = function: p
  call = function: p
interval = table:
  time = 10
  count = 0
  running = false
  stop = function: p
battery = table:
function not available on this camera
stack traceback:
[C]: in ?
[C]: in for iterator 'for iterator'
ML/SCRIPTS/LIB/logger.lua:125: in function 'logger.serialize'
ML/SCRIPTS/api_test.lua:36: in function <ML/SCRIPTS/api_test.lua:35>
[C]: in function 'globals.xpcall'
ML/SCRIPTS/api_test.lua:35: in function 'globals.print_table'
ML/SCRIPTS/api_test.lua:81: in function 'globals.generic_tests'
ML/SCRIPTS/api_test.lua:1338: in function 'globals.api_tests'
ML/SCRIPTS/api_test.lua:1364: in main chunktask = table:
  yield = function: p
  create = function: p
property = table:
Generic tests completed.

Module tests...
Testing file I/O...
Copy test: autoexec.bin -> tmp.bin
Copy test OK
Append test: tmp.txt
Append test OK
Rename test: apple.txt -> banana.txt
Rename test OK
Rename test: apple.txt -> ML/banana.txt
Rename test OK
File I/O tests completed.

Testing Canon GUI functions...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Pause LiveView...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Start LiveView...
Pause LiveView...
Resume LiveView...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Start LiveView...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Canon GUI tests completed.

Testing ML menu API...




[Pass] is_play_mode() => 0x1
[Pass] src = fio_malloc(size) => 0x4a28409c
[Pass] dst = fio_malloc(size) => 0x4aa880a8
[Pass] memcmp(dst, src, 4097) => 0xffffffc2
[Pass] edmac_memcpy(dst, src, 4097) => 0x4aa880a8
[Pass] memcmp(dst, src, 4097) => 0x0
[Pass] edmac_memcpy(dst, src, 4097) => 0x4aa880a8
[Pass] memcmp(dst, src, size) => 0xffffffee
[Pass] edmac_memcpy(dst, src, size) => 0x4aa880a8
[Pass] memcmp(dst, src, size) => 0x0
[Pass] memcmp(dst, src, size) => 0x6a
[Pass] edmac_memcpy_start(dst, src, size) => 0x4aa880a8
       dt => 0x2949
[Pass] copied => 0x4010d8
[Pass] copied => 0x4010d8
[Pass] copied => 0x4010d8
[Pass] memcmp(dst, src, copied) => 0x0
[Pass] memcmp(dst, src, copied + 16) => 0x84
       edmac_memcpy_finish()
       free(src)
       free(dst)
Cache test A (EDMAC on BMP buffer)...
[Pass] bmp = bmp_load("ML/CROPMKS/CINESCO2.BMP", 1) => 0x7a0274
[Pass] old => 0x0
[Pass] irq => 0xc0
[Pass] differences => 0x7af
[Pass] old => 0x0
[Pass] irq => 0xc0
[Pass] differences => 0x0
Cache test B (FIO on 8K buffer)...
[Pass] tries[0] => 0x105
[Pass] tries[1] => 0xef
[Pass] tries[2] => 0x115
[Pass] tries[3] => 0xdf
[Pass] failr[0] => 0x94
[Pass] failw[0] => 0xdd
[Pass] failr[1] => 0x63
[Pass] failw[1] => 0x0
[Pass] failr[2] => 0x0
[Pass] failw[2] => 0xf1
[Pass] failr[3] => 0x0
[Pass] failw[3] => 0x0
       times[0] / tries[0] => 0x14
       times[1] / tries[1] => 0x14
       times[2] / tries[2] => 0x16
       times[3] / tries[3] => 0x16
Cache tests finished.

[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[FAIL] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] f = FIO_CreateFile("test.dat") => 0x3
[Pass] FIO_WriteFile(f, (void*)0xFF000000, 0x10000) => 0x10000
[Pass] FIO_WriteFile(f, (void*)0xFF000000, 0x10000) => 0x10000
       FIO_CloseFile(f)
[Pass] FIO_GetFileSize("test.dat", &size) => 0x0
[Pass] size => 0x20000
[Pass] p = (void*)_alloc_dma_memory(0x20000) => 0x407f9bfc
[Pass] f = FIO_OpenFile("test.dat", O_RDONLY | O_SYNC) => 0x3
[Pass] FIO_ReadFile(f, p, 0x20000) => 0x20000
       FIO_CloseFile(f)
       _free_dma_memory(p)
[Pass] count => 0x3a98
[Pass] buf = fio_malloc(0x1000000) => 0x4a28409c
[Pass] FIO_GetFileSize_direct("test.dat") => 0x82000000
[Pass] f = FIO_OpenFile("test.dat", O_RDWR | O_SYNC) => 0x3
[Pass] FIO_SeekSkipFile(f, 0, SEEK_END) => 0x82000000
[Pass] FIO_WriteFile(f, buf, 0x10) => 0x10
[Pass] FIO_SeekSkipFile(f, -0x20, SEEK_END) => 0x81fffff0
[Pass] FIO_WriteFile(f, buf, 0x30) => 0x30
[Pass] FIO_SeekSkipFile(f, 0x20, SEEK_SET) => 0x20
[Pass] FIO_SeekSkipFile(f, 0x30, SEEK_CUR) => 0x50
[Pass] FIO_SeekSkipFile(f, -0x20, SEEK_CUR) => 0x30
[Pass] FIO_GetFileSize_direct("test.dat") => 0x82000020
[Pass] is_file("test.dat") => 0x1
[Pass] FIO_RemoveFile("test.dat") => 0x0
[Pass] is_file("test.dat") => 0x0
[Pass] SetTimerAfter(0, timer_cbr, overrun_cbr, 0) => 0x15
[Pass] timer_func => 0x2
[Pass] SetTimerAfter(1000, timer_cbr, overrun_cbr, 0) => 0xaa1c
       msleep(900)
[Pass] timer_func => 0x0
       msleep(200)
[Pass] timer_func => 0x1
[Pass] ABS((timer_time/1000 - t0) - 1000) => 0x3
[Pass] ABS((timer_arg - ta0) - 1000) => 0xa
[Pass] timer = SetTimerAfter(1000, timer_cbr, overrun_cbr, 0) => 0xaa8e
       msleep(400)
       CancelTimer(timer)
[Pass] timer_func => 0x0
       msleep(1500)
[Pass] timer_func => 0x0
[Pass] SetHPTimerAfterNow(0, timer_cbr, overrun_cbr, 0) => 0x15
[Pass] timer_func => 0x2
[Pass] SetHPTimerAfterNow(100000, timer_cbr, overrun_cbr, 0) => 0x1eeae
       msleep(90)
[Pass] timer_func => 0x0
       msleep(20)
[Pass] timer_func => 0x1
[Pass] ABS(DeltaT(timer_time, t0) - 100000) => 0x129
[Pass] ABS(DeltaT(timer_arg, ta0) - 100000) => 0xff
[Pass] ABS((get_us_clock_value() - t0) - 110000) => 0x1d0
[Pass] SetHPTimerAfterNow(90000, next_tick_cbr, overrun_cbr, 0) => 0x1eeb0
       msleep(80)
[Pass] timer_func => 0x0
       msleep(20)
[Pass] timer_func => 0x3
       msleep(80)
[Pass] timer_func => 0x3
       msleep(20)
[Pass] timer_func => 0x1
[Pass] ABS(DeltaT(timer_time, t0) - 300000) => 0x25c
[Pass] ABS(DeltaT(timer_arg, ta0) - 300000) => 0x23b
[Pass] ABS((get_us_clock_value() - t0) - 310000) => 0x32d
       t0 = *(uint32_t*)0xC0242014 => 0x1ee
       msleep(250)
       t1 = *(uint32_t*)0xC0242014 => 0x3bc41
[Pass] ABS(MOD(t1-t0, 1048576)/1000 - 250) => 0x6
       LoadCalendarFromRTC( &now )
       s0 = now.tm_sec => 0x1d
       Date/time: 2017/12/24 16:41:29
       msleep(1500)
       LoadCalendarFromRTC( &now )
       s1 = now.tm_sec => 0x1f
[Pass] MOD(s1-s0, 60) => 0x2
[Pass] MOD(s1-s0, 60) => 0x2
       m0 = MALLOC_FREE_MEMORY => 0x20198
[Pass] p = (void*)_malloc(50*1024) => 0x11f668
[Pass] CACHEABLE(p) => 0x11f668
       m1 = MALLOC_FREE_MEMORY => 0x13988
       _free(p)
       m2 = MALLOC_FREE_MEMORY => 0x20198
[Pass] ABS((m0-m1) - 50*1024) => 0x10
[Pass] ABS(m0-m2) => 0x0
       m0 = GetFreeMemForAllocateMemory() => 0x2f9634
[Pass] p = (void*)_AllocateMemory(256*1024) => 0x7f9bbc
[Pass] CACHEABLE(p) => 0x7f9bbc
       m1 = GetFreeMemForAllocateMemory() => 0x2b9628
       _FreeMemory(p)
       m2 = GetFreeMemForAllocateMemory() => 0x2f9634
[Pass] ABS((m0-m1) - 256*1024) => 0xc
[Pass] ABS(m0-m2) => 0x0
       m01 = MALLOC_FREE_MEMORY => 0x20198
       m02 = GetFreeMemForAllocateMemory() => 0x2f9634
[Pass] p = (void*)_alloc_dma_memory(256*1024) => 0x407f9bfc
[Pass] UNCACHEABLE(p) => 0x407f9bfc
[Pass] CACHEABLE(p) => 0x7f9bfc
[Pass] UNCACHEABLE(CACHEABLE(p)) => 0x407f9bfc
       _free_dma_memory(p)
[Pass] p = (void*)_shoot_malloc(24*1024*1024) => 0x42200068
[Pass] UNCACHEABLE(p) => 0x42200068
       _shoot_free(p)
       m11 = MALLOC_FREE_MEMORY => 0x20198
       m12 = GetFreeMemForAllocateMemory() => 0x2f9634
[Pass] ABS(m01-m11) => 0x0
[Pass] ABS(m02-m12) => 0x0
[Pass] suite = shoot_malloc_suite_contig(24*1024*1024) => 0x11f668
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x1
[Pass] suite->size => 0x1800000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x11f690
[Pass] chunk->signature => 'MemChunk'
[Pass] chunk->size => 0x1800000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42200064
[Pass] UNCACHEABLE(p) => 0x42200064
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] suite = shoot_malloc_suite_contig(0) => 0x11f668
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x1
[Pass] suite->size => 0x1f44000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x11f690
[Pass] chunk->signature => 'MemChunk'
[Pass] chunk->size => 0x1f44000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4ddc0064
[Pass] UNCACHEABLE(p) => 0x4ddc0064
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] suite = shoot_malloc_suite(64*1024*1024) => 0x11f668
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x7
[Pass] suite->size => 0x4000000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x11f690
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x1738000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4a284088
[Pass] UNCACHEABLE(p) => 0x4a284088
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f6f0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3534000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42200064
[Pass] UNCACHEABLE(p) => 0x42200064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f728
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3934000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x419ff0a4
[Pass] UNCACHEABLE(p) => 0x419ff0a4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f760
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3a0c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x49f240e4
[Pass] UNCACHEABLE(p) => 0x49f240e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f798
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3ae4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x47f240e4
[Pass] UNCACHEABLE(p) => 0x47f240e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f7d0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3bbc000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x45f240e4
[Pass] UNCACHEABLE(p) => 0x45f240e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f808
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x4000000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4ddc0064
[Pass] UNCACHEABLE(p) => 0x4ddc0064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x0
[Pass] total => 0x4000000
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] suite = shoot_malloc_suite(0) => 0x11f668
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x7
[Pass] suite->size => 0x5b00000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x11f690
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x1738000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4a284088
[Pass] UNCACHEABLE(p) => 0x4a284088
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f6f0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3534000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42200064
[Pass] UNCACHEABLE(p) => 0x42200064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f728
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3934000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x419ff0a4
[Pass] UNCACHEABLE(p) => 0x419ff0a4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f760
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3a0c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x49f240e4
[Pass] UNCACHEABLE(p) => 0x49f240e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f798
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3ae4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x47f240e4
[Pass] UNCACHEABLE(p) => 0x47f240e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f7d0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3bbc000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x45f240e4
[Pass] UNCACHEABLE(p) => 0x45f240e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x11f808
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x5b00000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4ddc0064
[Pass] UNCACHEABLE(p) => 0x4ddc0064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x0
[Pass] total => 0x5b00000
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] strlen("abc") => 0x3
[Pass] strlen("qwertyuiop") => 0xa
[Pass] strlen("") => 0x0
[Pass] strcpy(msg, "hi there") => 0x1b3c9c
[Pass] msg => 'hi there'
[Pass] snprintf(a, sizeof(a), "foo") => 0x3
[Pass] snprintf(b, sizeof(b), "foo") => 0x3
[Pass] strcmp(a, b) => 0x0
[Pass] snprintf(a, sizeof(a), "bar") => 0x3
[Pass] snprintf(b, sizeof(b), "baz") => 0x3
[Pass] strcmp(a, b) => 0xfffffff8
[Pass] snprintf(a, sizeof(a), "Display") => 0x7
[Pass] snprintf(b, sizeof(b), "Defishing") => 0x9
[Pass] strcmp(a, b) => 0x4
[Pass] snprintf(buf, 3, "%d", 1234) => 0x2
[Pass] buf => '12'
[Pass] memcpy(foo, bar, 6) => 0x1b3c80
[Pass] foo => 'asdfghuiop'
[Pass] memset(bar, '*', 5) => 0x1b3c60
[Pass] bar => '*****hjkl;'
       bzero32(bar + 5, 5)
[Pass] bar => '****'
       EngDrvOut(LCD_Palette[0], 0x1234)
[Pass] shamem_read(LCD_Palette[0]) => 0x1234
       call("TurnOnDisplay")
[Pass] DISPLAY_IS_ON => 0x1
       call("TurnOffDisplay")
[Pass] DISPLAY_IS_ON => 0x0
       call("TurnOnDisplay")
[Pass] DISPLAY_IS_ON => 0x1
       task_create("test", 0x1c, 0x1000, test_task, 0) => 0xc00600ac
[Pass] test_task_created => 0x1
[Pass] get_current_task_name() => 'run_test'
[Pass] task_max => 0x68
[Pass] task_max => 0x68
[Pass] mq = mq ? mq : (void*)msg_queue_create("test", 5) => 0xc00800b2
[Pass] msg_queue_post(mq, 0x1234567) => 0x0
[Pass] msg_queue_receive(mq, (struct event **) &m, 500) => 0x0
[Pass] m => 0x1234567
[Pass] msg_queue_receive(mq, (struct event **) &m, 500) => 0x9
[Pass] sem = sem ? sem : create_named_semaphore("test", 1) => 0xc00a024e
[Pass] take_semaphore(sem, 500) => 0x0
[Pass] take_semaphore(sem, 500) => 0x9
[Pass] give_semaphore(sem) => 0x0
[Pass] take_semaphore(sem, 500) => 0x0
[Pass] give_semaphore(sem) => 0x0
[Pass] rlock = rlock ? rlock : CreateRecursiveLock(0) => 0xc00c00c2
[Pass] AcquireRecursiveLock(rlock, 500) => 0x0
[Pass] AcquireRecursiveLock(rlock, 500) => 0x0
[Pass] ReleaseRecursiveLock(rlock) => 0x0
[Pass] ReleaseRecursiveLock(rlock) => 0x0
[Pass] ReleaseRecursiveLock(rlock) => 0xf
       SetGUIRequestMode(1); msleep(1000);
[Pass] CURRENT_GUI_MODE => 0x1
       SetGUIRequestMode(2); msleep(1000);
[Pass] CURRENT_GUI_MODE => 0x2
       SetGUIRequestMode(0); msleep(1000);
[Pass] CURRENT_GUI_MODE => 0x0
[Pass] display_idle() => 0x1
       GUI_Control(BGMT_PLAY, 0, 0, 0); msleep(1000);
[Pass] PLAY_MODE => 0x1
[Pass] MENU_MODE => 0x0
       GUI_Control(BGMT_MENU, 0, 0, 0); msleep(1000);
[Pass] MENU_MODE => 0x1
[Pass] PLAY_MODE => 0x0
[Pass] dialog->type => 'DIALOG'
       GUI_Control(BGMT_MENU, 0, 0, 0); msleep(500);
[Pass] MENU_MODE => 0x0
[Pass] PLAY_MODE => 0x0
       SW1(1,100)
[Pass] HALFSHUTTER_PRESSED => 0x1
       SW1(0,100)
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x1
[Pass] is_pure_play_movie_mode() => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x0
[Pass] is_pure_play_movie_mode() => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x0
[FAIL] is_pure_play_movie_mode() => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x0
[Pass] is_pure_play_movie_mode() => 0x0
=========================================================
Test complete, 12167 passed, 12 failed.
.


scherbakoff.dima

I've just run tests on 100D/SL1. Test 19.12 build for some hours of shooting with extensive use of ML photo pictures -- everything is OK for me. Cannot say anything about video because I don't shoot it.

I've got great stuck after stub tests run. Red card light didn't stop after some minutes after pushing switch to off state. Had to remove battery to get camera reboot. Reboot was a bit longer than usual. Currently ML is running normally.

p.s. Compared stub log to last poster's one -- looks like mine hanged abnormally. How can I help to debug it? I'm not able to build ML myself because my big and heavy laptop is at university's dormitory and lacks proper internet connection (biggest university at Ural thinks that students don't need stable internet access  :D ).

UPD reason: fixed small typo



===============================================================================
ML/SCRIPTS/API_TEST.LUA - 2017-12-21 20:19:35
===============================================================================

Strict mode tests...
Strict mode tests passed.

Generic tests...
arg = table:
  [0] = "API_TEST.LUA"
camera = table:
  shutter = table:
    raw = 0
    apex = -7.
    ms = 0
    value = 0
  aperture = table:
    raw = 40
    apex = 4
    value = 4
    min = table:
      raw = 40
      apex = 4
      value = 4
    max = table:
      raw = 80
      apex = 9
      value = 22.6
  iso = table:
    raw = 0
    apex = 0
    value = 0
  ec = table:
    raw = 5
    value = 0.624999
  flash_ec = table:
    raw = -11
    value = -1.375
  kelvin = 6400
  mode = 2
  metering_mode = 3
  drive_mode = 1
  model = "Canon EOS 100D"
  model_short = "100D"
  firmware = "1.0.1"
  temperature = 153
  gui = table:
    menu = false
    play = false
    play_photo = false
    play_movie = false
    qr = false
    idle = true
  wait = function: p
  reboot = function: p
  bulb = function: p
  burst = function: p
  shoot = function: p
event = table:
  pre_shoot = nil
  post_shoot = nil
  shoot_task = nil
  seconds_clock = nil
  keypress = nil
  custom_picture_taking = nil
  intervalometer = nil
  config_save = nil
console = table:
  show = function: p
  write = function: p
  clear = function: p
  hide = function: p
lv = table:
  enabled = false
  paused = false
  running = false
  zoom = 1
  overlays = false
  pause = function: p
  start = function: p
  resume = function: p
  info = function: p
  wait = function: p
  stop = function: p
lens = table:
  name = "EF-S55-250mm f/4-5.6 IS STM"
  focal_length = 0
  focus_distance = 90
  hyperfocal = 0
  dof_near = 0
  dof_far = 0
  af = true
  af_mode = 0
  focus = function: p
  autofocus = function: p
display = table:
  idle = nil
  height = 480
  width = 720
  off = function: p
  pixel = function: p
  clear = function: p
  notify_box = function: p
  on = function: p
  circle = function: p
  screenshot = function: p
  load = function: p
  draw = function: p
  rect = function: p
  line = function: p
  print = function: p
key = table:
  last = 10
  press = function: p
  wait = function: p
menu = table:
  visible = false
  set = function: p
  select = function: p
  block = function: p
  get = function: p
  close = function: p
  new = function: p
  open = function: p
movie = table:
  recording = false
  stop = function: p
  start = function: p
dryos = table:
  clock = 63
  ms_clock = 63676
  image_prefix = "IMG_"
  dcim_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "B:/DCIM/"
    path = "B:/DCIM/100CANON/"
  config_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "ML/"
    path = "ML/SETTINGS/"
  ml_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 303
    folder_number = 100
    free_space = 7248608
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  shooting_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 303
    folder_number = 100
    free_space = 7248608
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  date = table:
    year = 2017
    min = 19
    day = 21
    hour = 20
    wday = 5
    yday = 355
    sec = 36
    isdst = false
    month = 12
  remove = function: p
  rename = function: p
  directory = function: p
  call = function: p
interval = table:
  time = 1
  count = 0
  running = false
  stop = function: p
battery = table:
function not available on this camera
stack traceback:
[C]: in ?
[C]: in for iterator 'for iterator'
ML/SCRIPTS/LIB/logger.lua:125: in function 'logger.serialize'
ML/SCRIPTS/API_TEST.LUA:36: in function <ML/SCRIPTS/API_TEST.LUA:35>
[C]: in function 'globals.xpcall'
ML/SCRIPTS/API_TEST.LUA:35: in function 'globals.print_table'
ML/SCRIPTS/API_TEST.LUA:81: in function 'globals.generic_tests'
ML/SCRIPTS/API_TEST.LUA:1338: in function 'globals.api_tests'
ML/SCRIPTS/API_TEST.LUA:1364: in main chunktask = table:
  create = function: p
  yield = function: p
property = table:
Generic tests completed.

Module tests...
Testing file I/O...
Copy test: autoexec.bin -> tmp.bin
Copy test OK
Append test: tmp.txt
Append test OK
Rename test: apple.txt -> banana.txt
Rename test OK
Rename test: apple.txt -> ML/banana.txt
Rename test OK
File I/O tests completed.

Testing Canon GUI functions...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Pause LiveView...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Start LiveView...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Resume LiveView...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Resume LiveView...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...

===============================================================================
ML/SCRIPTS/API_TEST.LUA - 2017-12-26 12:42:42
===============================================================================

Strict mode tests...
Strict mode tests passed.

Generic tests...
arg = table:
  [0] = "API_TEST.LUA"
camera = table:
  shutter = table:
    raw = 0
    apex = -7.
    ms = 0
    value = 0
  aperture = table:
    raw = 40
    apex = 4
    value = 4
    min = table:
      raw = 40
      apex = 4
      value = 4
    max = table:
      raw = 80
      apex = 9
      value = 22.6
  iso = table:
    raw = 0
    apex = 0
    value = 0
  ec = table:
    raw = 0
    value = 0
  flash_ec = table:
    raw = 16
    value = 2
  kelvin = 6400
  mode = 2
  metering_mode = 1
  drive_mode = 1
  model = "Canon EOS 100D"
  model_short = "100D"
  firmware = "1.0.1"
  temperature = 160
  gui = table:
    menu = false
    play = false
    play_photo = false
    play_movie = false
    qr = false
    idle = true
  wait = function: p
  shoot = function: p
  reboot = function: p
  bulb = function: p
  burst = function: p
event = table:
  pre_shoot = nil
  post_shoot = nil
  shoot_task = nil
  seconds_clock = nil
  keypress = nil
  custom_picture_taking = nil
  intervalometer = nil
  config_save = nil
console = table:
  show = function: p
  hide = function: p
  clear = function: p
  write = function: p
lv = table:
  enabled = false
  paused = false
  running = false
  zoom = 1
  overlays = false
  wait = function: p
  start = function: p
  stop = function: p
  info = function: p
  pause = function: p
  resume = function: p
lens = table:
  name = "EF-S55-250mm f/4-5.6 IS STM"
  focal_length = 0
  focus_distance = 90
  hyperfocal = 0
  dof_near = 0
  dof_far = 0
  af = true
  af_mode = 0
  autofocus = function: p
  focus = function: p
display = table:
  idle = nil
  height = 480
  width = 720
  off = function: p
  draw = function: p
  clear = function: p
  notify_box = function: p
  rect = function: p
  pixel = function: p
  load = function: p
  on = function: p
  line = function: p
  screenshot = function: p
  print = function: p
  circle = function: p
key = table:
  last = 10
  press = function: p
  wait = function: p
menu = table:
  visible = false
  get = function: p
  new = function: p
  close = function: p
  set = function: p
  select = function: p
  open = function: p
  block = function: p
movie = table:
  recording = false
  stop = function: p
  start = function: p
dryos = table:
  clock = 29
  ms_clock = 29363
  image_prefix = "IMG_"
  dcim_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "B:/DCIM/"
    path = "B:/DCIM/100CANON/"
  config_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "ML/"
    path = "ML/SETTINGS/"
  ml_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 482
    folder_number = 100
    free_space = 5351136
    type = "SD"
    path = "B:/"
    _card_ptr = userdata
  shooting_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 482
    folder_number = 100
    free_space = 5351136
    type = "SD"
    path = "B:/"
    _card_ptr = userdata
  date = table:
    isdst = false
    month = 12
    year = 2017
    sec = 43
    min = 42
    yday = 360
    wday = 3
    hour = 12
    day = 26
  directory = function: p
  call = function: p
  rename = function: p
  remove = function: p
interval = table:
  time = 1
  count = 0
  running = false
  stop = function: p
battery = table:
function not available on this camera
stack traceback:
[C]: in ?
[C]: in for iterator 'for iterator'
ML/SCRIPTS/LIB/logger.lua:125: in function 'logger.serialize'
ML/SCRIPTS/API_TEST.LUA:36: in function <ML/SCRIPTS/API_TEST.LUA:35>
[C]: in function 'globals.xpcall'
ML/SCRIPTS/API_TEST.LUA:35: in function 'globals.print_table'
ML/SCRIPTS/API_TEST.LUA:81: in function 'globals.generic_tests'
ML/SCRIPTS/API_TEST.LUA:1338: in function 'globals.api_tests'
ML/SCRIPTS/API_TEST.LUA:1364: in main chunktask = table:
  yield = function: p
  create = function: p
property = table:
Generic tests completed.

Module tests...
Testing file I/O...
Copy test: autoexec.bin -> tmp.bin
Copy test OK
Append test: tmp.txt
Append test OK
Rename test: apple.txt -> banana.txt
Rename test OK
Rename test: apple.txt -> ML/banana.txt
Rename test OK
File I/O tests completed.

Testing Canon GUI functions...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Start LiveView...
Pause LiveView...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Resume LiveView...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Resume LiveView...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Resume LiveView...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Canon GUI tests completed.

Testing ML menu API...



[Pass] is_play_mode() => 0x1
[Pass] src = fio_malloc(size) => 0x4a8240a8
[Pass] dst = fio_malloc(size) => 0x4b0280b4
[Pass] memcmp(dst, src, 4097) => 0xdb
[Pass] edmac_memcpy(dst, src, 4097) => 0x4b0280b4
[Pass] memcmp(dst, src, 4097) => 0x0
[Pass] edmac_memcpy(dst, src, 4097) => 0x4b0280b4
[Pass] memcmp(dst, src, size) => 0x5d
[Pass] edmac_memcpy(dst, src, size) => 0x4b0280b4
[Pass] memcmp(dst, src, size) => 0x0
[Pass] memcmp(dst, src, size) => 0xffffff7f
[Pass] edmac_memcpy_start(dst, src, size) => 0x4b0280b4
       dt => 0x28e5
[Pass] copied => 0x40144c
[Pass] copied => 0x40144c
[Pass] copied => 0x40144c
[Pass] memcmp(dst, src, copied) => 0x0
[Pass] memcmp(dst, src, copied + 16) => 0x12
       edmac_memcpy_finish()
       free(src)
       free(dst)
Cache test A (EDMAC on BMP buffer)...
[Pass] bmp = bmp_load("ML/CROPMKS/CINESCO2.BMP", 1) => 0xeedf8
[Pass] old => 0x0
[Pass] irq => 0xc0
[Pass] differences => 0xdcf
[Pass] old => 0x0
[Pass] irq => 0xc0
[Pass] differences => 0x0
Cache test B (FIO on 8K buffer)...
[Pass] tries[0] => 0xf2
[Pass] tries[1] => 0x102
[Pass] tries[2] => 0x10a
[Pass] tries[3] => 0xea
[Pass] failr[0] => 0x6d
[Pass] failw[0] => 0xb2
[Pass] failr[1] => 0x71
[Pass] failw[1] => 0x0
[Pass] failr[2] => 0x0
[Pass] failw[2] => 0xb1
[Pass] failr[3] => 0x0
[Pass] failw[3] => 0x0
       times[0] / tries[0] => 0x23
       times[1] / tries[1] => 0x23
       times[2] / tries[2] => 0x25
       times[3] / tries[3] => 0x26
Cache tests finished.

[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x2
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x2
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x2
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x2
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x2
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] f = FIO_CreateFile("test.dat") => 0x3
[Pass] FIO_WriteFile(f, (void*)0xFF000000, 0x10000) => 0x10000
[Pass] FIO_WriteFile(f, (void*)0xFF000000, 0x10000) => 0x10000
       FIO_CloseFile(f)
[Pass] FIO_GetFileSize("test.dat", &size) => 0x0
[Pass] size => 0x20000
[Pass] p = (void*)_alloc_dma_memory(0x20000) => 0x40826a44
[Pass] f = FIO_OpenFile("test.dat", O_RDONLY | O_SYNC) => 0x3
[Pass] FIO_ReadFile(f, p, 0x20000) => 0x20000
       FIO_CloseFile(f)
       _free_dma_memory(p)
[Pass] count => 0x3a98
[Pass] buf = fio_malloc(0x1000000) => 0x4a8240a8
[Pass] FIO_GetFileSize_direct("test.dat") => 0x82000000
[Pass] f = FIO_OpenFile("test.dat", O_RDWR | O_SYNC) => 0x3
[Pass] FIO_SeekSkipFile(f, 0, SEEK_END) => 0x82000000
[Pass] FIO_WriteFile(f, buf, 0x10) => 0x10
[Pass] FIO_SeekSkipFile(f, -0x20, SEEK_END) => 0x81fffff0
[Pass] FIO_WriteFile(f, buf, 0x30) => 0x30
[Pass] FIO_SeekSkipFile(f, 0x20, SEEK_SET) => 0x20
[Pass] FIO_SeekSkipFile(f, 0x30, SEEK_CUR) => 0x50
[Pass] FIO_SeekSkipFile(f, -0x20, SEEK_CUR) => 0x30
[Pass] FIO_GetFileSize_direct("test.dat") => 0x82000020
[Pass] is_file("test.dat") => 0x1
[Pass] FIO_RemoveFile("test.dat") => 0x0
[Pass] is_file("test.dat") => 0x0
[Pass] SetTimerAfter(0, timer_cbr, overrun_cbr, 0) => 0x15
[Pass] timer_func => 0x2
[Pass] SetTimerAfter(1000, timer_cbr, overrun_cbr, 0) => 0xdd54
       msleep(900)
[Pass] timer_func => 0x0
       msleep(200)
[Pass] timer_func => 0x1
[Pass] ABS((timer_time/1000 - t0) - 1000) => 0x1
[Pass] ABS((timer_arg - ta0) - 1000) => 0xa
[Pass] timer = SetTimerAfter(1000, timer_cbr, overrun_cbr, 0) => 0xddb4
       msleep(400)
       CancelTimer(timer)
[Pass] timer_func => 0x0
       msleep(1500)
[Pass] timer_func => 0x0
[Pass] SetHPTimerAfterNow(0, timer_cbr, overrun_cbr, 0) => 0x15
[Pass] timer_func => 0x2
[Pass] SetHPTimerAfterNow(100000, timer_cbr, overrun_cbr, 0) => 0x32efc
       msleep(90)
[Pass] timer_func => 0x0
       msleep(20)
[Pass] timer_func => 0x1
[Pass] ABS(DeltaT(timer_time, t0) - 100000) => 0x123
[Pass] ABS(DeltaT(timer_arg, ta0) - 100000) => 0x104
[Pass] ABS((get_us_clock_value() - t0) - 110000) => 0x47
[Pass] SetHPTimerAfterNow(90000, next_tick_cbr, overrun_cbr, 0) => 0x32efe
       msleep(80)
[Pass] timer_func => 0x0
       msleep(20)
[Pass] timer_func => 0x3
       msleep(80)
[Pass] timer_func => 0x3
       msleep(20)
[Pass] timer_func => 0x1
[Pass] ABS(DeltaT(timer_time, t0) - 300000) => 0xcc
[Pass] ABS(DeltaT(timer_arg, ta0) - 300000) => 0xad
[Pass] ABS((get_us_clock_value() - t0) - 310000) => 0x5f
       t0 = *(uint32_t*)0xC0242014 => 0x5e30f
       msleep(250)
       t1 = *(uint32_t*)0xC0242014 => 0x9af7c
[Pass] ABS(MOD(t1-t0, 1048576)/1000 - 250) => 0x2
       LoadCalendarFromRTC( &now )
       s0 = now.tm_sec => 0x32
       Date/time: 2017/12/26 12:35:50
       msleep(1500)
       LoadCalendarFromRTC( &now )
       s1 = now.tm_sec => 0x33
[Pass] MOD(s1-s0, 60) => 0x1
[Pass] MOD(s1-s0, 60) => 0x1
       m0 = MALLOC_FREE_MEMORY => 0x84b40
[Pass] p = (void*)_malloc(50*1024) => 0xfc628
[Pass] CACHEABLE(p) => 0xfc628
       m1 = MALLOC_FREE_MEMORY => 0x78330
       _free(p)
       m2 = MALLOC_FREE_MEMORY => 0x84b40
[Pass] ABS((m0-m1) - 50*1024) => 0x10
[Pass] ABS(m0-m2) => 0x0
       m0 = GetFreeMemForAllocateMemory() => 0x216298
[Pass] p = (void*)_AllocateMemory(256*1024) => 0xaa81c0
[Pass] CACHEABLE(p) => 0xaa81c0
       m1 = GetFreeMemForAllocateMemory() => 0x1d628c
       _FreeMemory(p)
       m2 = GetFreeMemForAllocateMemory() => 0x2162f8
[Pass] ABS((m0-m1) - 256*1024) => 0xc
[Pass] ABS(m0-m2) => 0x60
       m01 = MALLOC_FREE_MEMORY => 0x84b40
       m02 = GetFreeMemForAllocateMemory() => 0x2162f8
[Pass] p = (void*)_alloc_dma_memory(256*1024) => 0x40aa8200
[Pass] UNCACHEABLE(p) => 0x40aa8200
[Pass] CACHEABLE(p) => 0xaa8200
[Pass] UNCACHEABLE(CACHEABLE(p)) => 0x40aa8200
       _free_dma_memory(p)
[Pass] p = (void*)_shoot_malloc(24*1024*1024) => 0x42200068
[Pass] UNCACHEABLE(p) => 0x42200068
       _shoot_free(p)
       m11 = MALLOC_FREE_MEMORY => 0x84b40
       m12 = GetFreeMemForAllocateMemory() => 0x2162f8
[Pass] ABS(m01-m11) => 0x0
[Pass] ABS(m02-m12) => 0x0





a1ex

Updates:

- fixed issue #2824 (decimal number precision when printing; thanks dmilligan and aprofiti)
- all models now have the Sticky HalfShutter feature (the assertion at 424 was just a reminder for that); after understanding how it works, I see no reason why these wouldn't work on all models, but they are untested; please report back
- all models except EOS M have the Sticky DOF feature (same as above; EOS M doesn't have a DOF button)
- I could verify a large part of api_test.lua in QEMU
- DOF info fix from garry23 (mostly untested, sorry)
- yet another series of menu refactors and cleanups
- included some updates on auto bracketing and silent pictures (not exactly related to Lua)

Call for testers still valid (got reports for 4 camera models out of 16...)

If autofocus still fails, make sure the camera has something to lock focus on, and try disabling any sort of continuous AF you might have enabled in Canon menu. If it still doesn't work, that would require somebody who owns the troublesome camera to take a closer look.

garry23

@a1ex

Thanks for the new Lua experimental build.

Had a very quick look on my 5D3 this morning and things look good, i.e.dofs look ok and auto bracketing seems 'better'.

Once again cheers.

Garry

garry23

@a1ex

BTW is there a reason that, when auto bracketing, the process doesn't return to a 'normal' (liewview) screen view: Rather it stops at the 'last image taken' review screen, which I can clear with a half-shutter.

My Canon review is set to off.

Cheers

Garry

a1ex

Yes, it goes to PLAY mode to look at the last image. If you set the review to 2 seconds, it won't have to do that any more.

BTW, raw-based tools (such as Auto ETTR) are not able to use that trick, because the raw data is not available in PLAY mode (only in QuickReview).

garry23

That did it  :)

Thanks for the insight.

Cheers

Garry

Walter Schulz

650D:
HS: LV for more than 30 minutes, check!
DOF: Weird things happening with FRSP and sticky set. Hitting DOF preview button takes a pic, sometimes with "RAW error" message. Which info can I provide helping you hunting this one down?

a1ex

That one is likely hard to fix - the DOF button also sends half-shutter events. Will check later, but I expect similar behavior on all models.

Walter Schulz

Confirmed, same DOF issue with 7D. Haven't been able to get a single FRSP with 7D because "Raw error" happening all the time.

Another question btw: DOF sticky is not persistent. Gone after taking a pic. I suppose this is intentional but it would really be convinient to have this option persistent for macro focus stacking/intervalometer together with FRSP.

lojzik

70D
magiclantern-lua_fix.2018Jan20.70D112
STUBTEST.LOG
[Pass] is_play_mode() => 0x1
[Pass] src = fio_malloc(size) => 0x424100a8
[Pass] dst = fio_malloc(size) => 0x42c140b4
[Pass] memcmp(dst, src, 4097) => 0x6b
[Pass] edmac_memcpy(dst, src, 4097) => 0x42c140b4
[Pass] memcmp(dst, src, 4097) => 0x0
[Pass] edmac_memcpy(dst, src, 4097) => 0x42c140b4
[Pass] memcmp(dst, src, size) => 0x8f
[Pass] edmac_memcpy(dst, src, size) => 0x42c140b4
[Pass] memcmp(dst, src, size) => 0x0
[Pass] memcmp(dst, src, size) => 0xffffffae
[Pass] edmac_memcpy_start(dst, src, size) => 0x42c140b4
       dt => 0x16e4
[Pass] copied => 0x40114c
[Pass] copied => 0x40114c
[Pass] copied => 0x40114c
[Pass] memcmp(dst, src, copied) => 0x0
[Pass] memcmp(dst, src, copied + 16) => 0x77
       edmac_memcpy_finish()
       free(src)
       free(dst)
Cache test A (EDMAC on BMP buffer)...
[Pass] bmp = bmp_load("ML/CROPMKS/CINESCO2.BMP", 1) => 0x1269f0
[Pass] old => 0x0
[Pass] irq => 0xc0
[Pass] differences => 0x980
[Pass] old => 0x0
[Pass] irq => 0xc0
[Pass] differences => 0x0
Cache test B (FIO on 8K buffer)...
[Pass] tries[0] => 0xdc
[Pass] tries[1] => 0x10b
[Pass] tries[2] => 0x117
[Pass] tries[3] => 0xea
[Pass] failr[0] => 0x68
[Pass] failw[0] => 0x89
[Pass] failr[1] => 0x68
[Pass] failw[1] => 0x0
[Pass] failr[2] => 0x0
[Pass] failw[2] => 0xbe
[Pass] failr[3] => 0x0
[Pass] failw[3] => 0x0
       times[0] / tries[0] => 0x30
       times[1] / tries[1] => 0x2f
       times[2] / tries[2] => 0x3d
       times[3] / tries[3] => 0x32
Cache tests finished.

[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] f = FIO_CreateFile("test.dat") => 0x6
[Pass] FIO_WriteFile(f, (void*)0xFF000000, 0x10000) => 0x10000
[Pass] FIO_WriteFile(f, (void*)0xFF000000, 0x10000) => 0x10000
       FIO_CloseFile(f)
[Pass] FIO_GetFileSize("test.dat", &size) => 0x0
[Pass] size => 0x20000
[Pass] p = (void*)_alloc_dma_memory(0x20000) => 0x40933c18
[Pass] f = FIO_OpenFile("test.dat", O_RDONLY | O_SYNC) => 0x6
[Pass] FIO_ReadFile(f, p, 0x20000) => 0x20000
       FIO_CloseFile(f)
       _free_dma_memory(p)
[Pass] count => 0x3a98
[Pass] buf = fio_malloc(0x1000000) => 0x424100a8
[Pass] FIO_GetFileSize_direct("test.dat") => 0x82000000
[Pass] f = FIO_OpenFile("test.dat", O_RDWR | O_SYNC) => 0x6
[Pass] FIO_SeekSkipFile(f, 0, SEEK_END) => 0x82000000
[Pass] FIO_WriteFile(f, buf, 0x10) => 0x10
[Pass] FIO_SeekSkipFile(f, -0x20, SEEK_END) => 0x81fffff0
[Pass] FIO_WriteFile(f, buf, 0x30) => 0x30
[Pass] FIO_SeekSkipFile(f, 0x20, SEEK_SET) => 0x20
[Pass] FIO_SeekSkipFile(f, 0x30, SEEK_CUR) => 0x50
[Pass] FIO_SeekSkipFile(f, -0x20, SEEK_CUR) => 0x30
[Pass] FIO_GetFileSize_direct("test.dat") => 0x82000020
[Pass] is_file("test.dat") => 0x1
[Pass] FIO_RemoveFile("test.dat") => 0x0
[Pass] is_file("test.dat") => 0x0
[Pass] SetTimerAfter(0, timer_cbr, overrun_cbr, 0) => 0x15
[Pass] timer_func => 0x2
[Pass] SetTimerAfter(1000, timer_cbr, overrun_cbr, 0) => 0xac94
       msleep(900)
[Pass] timer_func => 0x0
       msleep(200)
[Pass] timer_func => 0x1
[Pass] ABS((timer_time/1000 - t0) - 1000) => 0x5
[Pass] ABS((timer_arg - ta0) - 1000) => 0xa
[Pass] timer = SetTimerAfter(1000, timer_cbr, overrun_cbr, 0) => 0xacfa
       msleep(400)
       CancelTimer(timer)
[Pass] timer_func => 0x0
       msleep(1500)
[Pass] timer_func => 0x0
[Pass] SetHPTimerAfterNow(0, timer_cbr, overrun_cbr, 0) => 0x15
[Pass] timer_func => 0x2
[Pass] SetHPTimerAfterNow(100000, timer_cbr, overrun_cbr, 0) => 0x38b3c
       msleep(90)
[Pass] timer_func => 0x0
       msleep(20)
[Pass] timer_func => 0x1
[Pass] ABS(DeltaT(timer_time, t0) - 100000) => 0xed
[Pass] ABS(DeltaT(timer_arg, ta0) - 100000) => 0xd2
[Pass] ABS((get_us_clock_value() - t0) - 110000) => 0x345
[Pass] SetHPTimerAfterNow(90000, next_tick_cbr, overrun_cbr, 0) => 0x38b3e
       msleep(80)
[Pass] timer_func => 0x0
       msleep(20)
[Pass] timer_func => 0x3
       msleep(80)
[Pass] timer_func => 0x3
       msleep(20)
[Pass] timer_func => 0x1
[Pass] ABS(DeltaT(timer_time, t0) - 300000) => 0x3be
[Pass] ABS(DeltaT(timer_arg, ta0) - 300000) => 0x3a0
[Pass] ABS((get_us_clock_value() - t0) - 310000) => 0x36a
       t0 = *(uint32_t*)0xC0242014 => 0x26e86
       msleep(250)
       t1 = *(uint32_t*)0xC0242014 => 0x61f5e
[Pass] ABS(MOD(t1-t0, 1048576)/1000 - 250) => 0x9
       LoadCalendarFromRTC( &now )
       s0 = now.tm_sec => 0xa
       Date/time: 2018/01/27 18:56:10
       msleep(1500)
       LoadCalendarFromRTC( &now )
       s1 = now.tm_sec => 0xc
[Pass] MOD(s1-s0, 60) => 0x2
[Pass] MOD(s1-s0, 60) => 0x2
       m0 = MALLOC_FREE_MEMORY => 0x37940
[Pass] p = (void*)_malloc(50*1024) => 0x128730
[Pass] CACHEABLE(p) => 0x128730
       m1 = MALLOC_FREE_MEMORY => 0x2b130
       _free(p)
       m2 = MALLOC_FREE_MEMORY => 0x37940
[Pass] ABS((m0-m1) - 50*1024) => 0x10
[Pass] ABS(m0-m2) => 0x0
       m0 = GetFreeMemForAllocateMemory() => 0x257b10
[Pass] p = (void*)_AllocateMemory(256*1024) => 0x933bd8
[Pass] CACHEABLE(p) => 0x933bd8
       m1 = GetFreeMemForAllocateMemory() => 0x217b04
       _FreeMemory(p)
       m2 = GetFreeMemForAllocateMemory() => 0x257b10
[Pass] ABS((m0-m1) - 256*1024) => 0xc
[Pass] ABS(m0-m2) => 0x0
       m01 = MALLOC_FREE_MEMORY => 0x37940
       m02 = GetFreeMemForAllocateMemory() => 0x257b10
[Pass] p = (void*)_alloc_dma_memory(256*1024) => 0x40933c18
[Pass] UNCACHEABLE(p) => 0x40933c18
[Pass] CACHEABLE(p) => 0x933c18
[Pass] UNCACHEABLE(CACHEABLE(p)) => 0x40933c18
       _free_dma_memory(p)
[Pass] p = (void*)_shoot_malloc(24*1024*1024) => 0x42410098
[Pass] UNCACHEABLE(p) => 0x42410098
       _shoot_free(p)
       m11 = MALLOC_FREE_MEMORY => 0x37940
       m12 = GetFreeMemForAllocateMemory() => 0x257b10
[Pass] ABS(m01-m11) => 0x0
[Pass] ABS(m02-m12) => 0x0
[Pass] suite = shoot_malloc_suite_contig(24*1024*1024) => 0x125120
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x1
[Pass] suite->size => 0x1800000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x125148
[Pass] chunk->signature => 'MemChunk'
[Pass] chunk->size => 0x1800000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42410094
[Pass] UNCACHEABLE(p) => 0x42410094
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] suite = shoot_malloc_suite_contig(0) => 0x125120
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x1
[Pass] suite->size => 0x2000000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x125148
[Pass] chunk->signature => 'MemChunk'
[Pass] chunk->size => 0x2000000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x48c00064
[Pass] UNCACHEABLE(p) => 0x48c00064
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] suite = shoot_malloc_suite(64*1024*1024) => 0x125120
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x3
[Pass] suite->size => 0x4000000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x125148
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x1f00000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42410094
[Pass] UNCACHEABLE(p) => 0x42410094
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1251a8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3f00000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x48c00064
[Pass] UNCACHEABLE(p) => 0x48c00064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1251e0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x4000000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4ac00070
[Pass] UNCACHEABLE(p) => 0x4ac00070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x0
[Pass] total => 0x4000000
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] suite = shoot_malloc_suite(0) => 0x125120
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x13
[Pass] suite->size => 0xf300000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x125148
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x1f00000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42410094
[Pass] UNCACHEABLE(p) => 0x42410094
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1251a8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x3f00000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x48c00064
[Pass] UNCACHEABLE(p) => 0x48c00064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1251e0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x4214000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4ac00070
[Pass] UNCACHEABLE(p) => 0x4ac00070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125218
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x42fc000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x48b140e4
[Pass] UNCACHEABLE(p) => 0x48b140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125250
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x43e4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x467140e4
[Pass] UNCACHEABLE(p) => 0x467140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125288
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x44cc000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5c9140e4
[Pass] UNCACHEABLE(p) => 0x5c9140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1252c0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x45b4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5a5140e4
[Pass] UNCACHEABLE(p) => 0x5a5140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1252f8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x469c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x581140e4
[Pass] UNCACHEABLE(p) => 0x581140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125330
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x4784000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4af140e4
[Pass] UNCACHEABLE(p) => 0x4af140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125368
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x486c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x443140e4
[Pass] UNCACHEABLE(p) => 0x443140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1253a0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x686c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x55e00064
[Pass] UNCACHEABLE(p) => 0x55e00064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1253d8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x6b80000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x57e00070
[Pass] UNCACHEABLE(p) => 0x57e00070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125410
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x8b80000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x58200064
[Pass] UNCACHEABLE(p) => 0x58200064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125448
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x8e94000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5a200070
[Pass] UNCACHEABLE(p) => 0x5a200070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125480
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xae94000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5a600064
[Pass] UNCACHEABLE(p) => 0x5a600064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1254b8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xb1a8000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5c600070
[Pass] UNCACHEABLE(p) => 0x5c600070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1254f0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xd1a8000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x44400064
[Pass] UNCACHEABLE(p) => 0x44400064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125528
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xd4bc000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x46400070
[Pass] UNCACHEABLE(p) => 0x46400070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125560
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xf300000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x46800064
[Pass] UNCACHEABLE(p) => 0x46800064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x0
[Pass] total => 0xf300000
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] strlen("abc") => 0x3
[Pass] strlen("qwertyuiop") => 0xa
[Pass] strlen("") => 0x0
[Pass] strcpy(msg, "hi there") => 0x1ec2bc
[Pass] msg => 'hi there'
[Pass] snprintf(a, sizeof(a), "foo") => 0x3
[Pass] snprintf(b, sizeof(b), "foo") => 0x3
[Pass] strcmp(a, b) => 0x0
[Pass] snprintf(a, sizeof(a), "bar") => 0x3
[Pass] snprintf(b, sizeof(b), "baz") => 0x3
[Pass] strcmp(a, b) => 0xfffffff8
[Pass] snprintf(a, sizeof(a), "Display") => 0x7
[Pass] snprintf(b, sizeof(b), "Defishing") => 0x9
[Pass] strcmp(a, b) => 0x4
[Pass] snprintf(buf, 3, "%d", 1234) => 0x2
[Pass] buf => '12'
[Pass] memcpy(foo, bar, 6) => 0x1ec2a0
[Pass] foo => 'asdfghuiop'
[Pass] memset(bar, '*', 5) => 0x1ec280
[Pass] bar => '*****hjkl;'
       bzero32(bar + 5, 5)
[Pass] bar => '****'
       EngDrvOut(LCD_Palette[0], 0x1234)
[Pass] shamem_read(LCD_Palette[0]) => 0x1234
       call("TurnOnDisplay")
[Pass] DISPLAY_IS_ON => 0x1
       call("TurnOffDisplay")
[Pass] DISPLAY_IS_ON => 0x0
       call("TurnOnDisplay")
[Pass] DISPLAY_IS_ON => 0x1
       task_create("test", 0x1c, 0x1000, test_task, 0) => 0xdeda00f0
[Pass] test_task_created => 0x1
[Pass] get_current_task_name() => 'run_test'
[Pass] task_max => 0x84
[Pass] task_max => 0x84
[Pass] mq = mq ? mq : (void*)msg_queue_create("test", 5) => 0xdedc00c8
[Pass] msg_queue_post(mq, 0x1234567) => 0x0
[Pass] msg_queue_receive(mq, (struct event **) &m, 500) => 0x0
[Pass] m => 0x1234567
[Pass] msg_queue_receive(mq, (struct event **) &m, 500) => 0x9
[Pass] sem = sem ? sem : create_named_semaphore("test", 1) => 0xdede025e
[Pass] take_semaphore(sem, 500) => 0x0
[Pass] take_semaphore(sem, 500) => 0x9
[Pass] give_semaphore(sem) => 0x0
[Pass] take_semaphore(sem, 500) => 0x0
[Pass] give_semaphore(sem) => 0x0
[Pass] rlock = rlock ? rlock : CreateRecursiveLock(0) => 0xdee000f2
[Pass] AcquireRecursiveLock(rlock, 500) => 0x0
[Pass] AcquireRecursiveLock(rlock, 500) => 0x0
[Pass] ReleaseRecursiveLock(rlock) => 0x0
[Pass] ReleaseRecursiveLock(rlock) => 0x0
[Pass] ReleaseRecursiveLock(rlock) => 0xf
       SetGUIRequestMode(1); msleep(1000);
[Pass] CURRENT_GUI_MODE => 0x1
       SetGUIRequestMode(2); msleep(1000);
[Pass] CURRENT_GUI_MODE => 0x2
       SetGUIRequestMode(0); msleep(1000);
[Pass] CURRENT_GUI_MODE => 0x0
[Pass] display_idle() => 0x1
       GUI_Control(BGMT_PLAY, 0, 0, 0); msleep(1000);
[Pass] PLAY_MODE => 0x1
[Pass] MENU_MODE => 0x0
       GUI_Control(BGMT_MENU, 0, 0, 0); msleep(1000);
[Pass] MENU_MODE => 0x1
[Pass] PLAY_MODE => 0x0
[Pass] dialog->type => 'DIALOG'
       GUI_Control(BGMT_MENU, 0, 0, 0); msleep(500);
[Pass] MENU_MODE => 0x0
[Pass] PLAY_MODE => 0x0
       SW1(1,100)
[Pass] HALFSHUTTER_PRESSED => 0x1
       SW1(0,100)
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x1
[Pass] is_pure_play_movie_mode() => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x0
[Pass] is_pure_play_movie_mode() => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x0
[Pass] is_pure_play_movie_mode() => 0x1
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x0
[Pass] is_pure_play_movie_mode() => 0x0
=========================================================
Test complete, 12809 passed, 10 failed.
.


LUATEST.LOG
===============================================================================
ML/SCRIPTS/API_TEST.LUA - 2018-1-27 19:25:29
===============================================================================

Strict mode tests...
Strict mode tests passed.

Generic tests...
arg = table:
  [0] = "API_TEST.LUA"
camera = table:
  shutter = table:
    raw = 75
    apex = 2.375
    ms = 193
    value = 0.192776
  aperture = table:
    raw = 32
    apex = 3.
    value = 2.8
    min = table:
      raw = 32
      apex = 3.
      value = 2.8
    max = table:
      raw = 80
      apex = 9.
      value = 22.6
  iso = table:
    raw = 104
    apex = 9.
    value = 1600
  ec = table:
    raw = 0
    value = 0
  flash_ec = table:
    raw = 0
    value = 0
  kelvin = 6400
  mode = 3
  metering_mode = 3
  drive_mode = 0
  model = "Canon EOS 70D"
  model_short = "70D"
  firmware = "1.1.2"
  temperature = 161
  gui = table:
    menu = false
    play = false
    play_photo = false
    play_movie = false
    qr = false
    idle = true
  reboot = function: p
  burst = function: p
  bulb = function: p
  wait = function: p
  shoot = function: p
event = table:
  pre_shoot = nil
  post_shoot = nil
  shoot_task = nil
  seconds_clock = nil
  keypress = nil
  custom_picture_taking = nil
  intervalometer = nil
  config_save = nil
console = table:
  write = function: p
  clear = function: p
  hide = function: p
  show = function: p
lv = table:
  enabled = false
  paused = false
  running = false
  zoom = 1
  overlays = false
  resume = function: p
  pause = function: p
  stop = function: p
  wait = function: p
  start = function: p
  info = function: p
lens = table:
  name = "EF-S24mm f/2.8 STM"
  focal_length = 0
  focus_distance = 90
  hyperfocal = 0
  dof_near = 0
  dof_far = 0
  af = true
  af_mode = 0
  focus = function: p
  autofocus = function: p
display = table:
  idle = nil
  height = 480
  width = 720
  on = function: p
  line = function: p
  rect = function: p
  load = function: p
  clear = function: p
  pixel = function: p
  screenshot = function: p
  draw = function: p
  circle = function: p
  notify_box = function: p
  off = function: p
  print = function: p
key = table:
  last = 10
  press = function: p
  wait = function: p
menu = table:
  visible = false
  get = function: p
  select = function: p
  new = function: p
  set = function: p
  block = function: p
  open = function: p
  close = function: p
movie = table:
  recording = false
  start = function: p
  stop = function: p
dryos = table:
  clock = 9
  ms_clock = 9957
  image_prefix = "IMG_"
  dcim_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "B:/DCIM/"
    path = "B:/DCIM/100CANON/"
  config_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "ML/"
    path = "ML/SETTINGS/"
  ml_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 4622
    folder_number = 100
    free_space = 14272384
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  shooting_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 4622
    folder_number = 100
    free_space = 14272384
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  date = table:
    day = 27
    month = 1
    sec = 30
    yday = 27
    min = 25
    isdst = false
    hour = 19
    year = 2018
    wday = 7
  directory = function: p
  rename = function: p
  call = function: p
  remove = function: p
interval = table:
  time = 10
  count = 0
  running = false
  stop = function: p
battery = table:
  level = 56
  id = 1
  performance = 0
  time = nil
  drain_rate = 18
task = table:
  yield = function: p
  create = function: p
property = table:
Generic tests completed.

Module tests...
Testing file I/O...
Copy test: autoexec.bin -> tmp.bin
Copy test OK
Append test: tmp.txt
Append test OK
Rename test: apple.txt -> banana.txt
Rename test OK
Rename test: apple.txt -> ML/banana.txt
Rename test OK
File I/O tests completed.

Testing Canon GUI functions...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Start LiveView...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Stop LiveView...
Start LiveView...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Enter PLAY mode...
Enter PLAY mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Start LiveView...
Pause LiveView...
Resume LiveView...
Enter PLAY mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Stop LiveView...
Start LiveView...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Resume LiveView...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Canon GUI tests completed.

Testing ML menu API...
Menu tests completed.

Testing picture taking functions...
Snap simulation test...
Single picture...
B:/DCIM/100CANON/IMG_4623.CR2: 27560045
B:/DCIM/100CANON/IMG_4623.JPG not found.
Two burst pictures...
Ideally, the camera should be in some continuous shooting mode (not checked).
B:/DCIM/100CANON/ABC_4624.CR2: 27558742
B:/DCIM/100CANON/ABC_4624.JPG not found.
B:/DCIM/100CANON/ABC_4625.CR2: 27568768
B:/DCIM/100CANON/ABC_4625.JPG not found.
Bracketed pictures...
B:/DCIM/100CANON/IMG_4626.CR2: 25058480
B:/DCIM/100CANON/IMG_4626.JPG not found.
B:/DCIM/100CANON/IMG_4627.CR2: 27565028
B:/DCIM/100CANON/IMG_4627.JPG not found.
B:/DCIM/100CANON/IMG_4628.CR2: 23739077
B:/DCIM/100CANON/IMG_4628.JPG not found.
Bulb picture...
Elapsed time: 13248
B:/DCIM/100CANON/IMG_4629.CR2: 14612305
B:/DCIM/100CANON/IMG_4629.JPG not found.
Picture taking tests completed.

Testing multitasking...
Only one task allowed to interrupt...
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Multitasking tests completed.

Testing half-shutter...
Half-shutter test OK.

Testing module 'lv'...
LiveView is running; stopping...
Starting LiveView...
Overlays: Canon
Overlays: Canon
Overlays: Canon
Overlays: ML
Overlays: ML
Overlays: disabled
Overlays: Canon
Overlays: Canon
Overlays: Canon
Overlays: Canon
Overlays: disabled
Overlays: ML
Overlays: disabled
Overlays: Canon
Overlays: Canon
Setting zoom to x1...
Setting zoom to x5...
Setting zoom to x10...
Setting zoom to x5...
Setting zoom to x1...
Setting zoom to x10...
Setting zoom to x1...
Pausing LiveView...
Resuming LiveView...
Stopping LiveView...
LiveView tests completed.


Testing lens focus functionality...
Autofocus outside LiveView...
Focus distance: 6310
Autofocus in LiveView...
Please trigger autofocus (half-shutter / AF-ON / * ).
19...18...17...16...15...Autofocus triggered.
Autofocus completed.
Focus distance: 1630
Focusing backward...
Focus distance: 655350
Focus motor position: 1824
Focusing forward with step size 3, wait=true...
...................
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 3, wait=true...
.....................
Focus distance: 655350
Focus motor position: 1824
Focus range: 19 steps forward, 21 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.
Focusing forward with step size 3, wait=false...
.............................................
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 3, wait=false...
................................................
Focus distance: 960
Focus motor position: 1569
Focus range: 45 steps forward, 48 steps backward.
Motor steps: 1534 forward, 1279 backward, 255 lost.
Focusing forward with step size 2, wait=true...
...
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 2, wait=true...
...
Focus distance: 655350
Focus motor position: 1824
Focus range: 128 steps forward, 127 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.
Focusing forward with step size 2, wait=false...
...
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 2, wait=false...
...
Focus distance: 655350
Focus motor position: 1824
Focus range: 154 steps forward, 152 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.
Focusing forward with step size 1, wait=true...
...
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 1, wait=true...
...
Focus distance: 655350
Focus motor position: 1824
Focus range: 456 steps forward, 456 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.
Focusing forward with step size 1, wait=false...
...
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 1, wait=false...
...
Focus distance: 655350
Focus motor position: 1824
Focus range: 464 steps forward, 467 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.

Focus test completed.

Testing exposure settings...
Camera    : Canon EOS 70D (70D) 1.1.2
Lens      : EF-S24mm f/2.8 STM
Shoot mode: 3
Shutter   : ,5 (raw 75, 0.192776s, 193ms, apex 2.375)
Aperture  : 2.8 (raw 32, f/2.8, apex 3.)
Av range  : 2.8..22 (raw 32..80, f/2.8..f/22.6, apex 3...9.)
ISO       : €1600 (raw 104, 1600, apex 9.)
EC        : 0.0 (raw 0, 0 EV)
Flash EC  : 0.0 (raw 0, 0 EV)
Setting shutter to random values...
Setting ISO to random values...
Setting aperture to random values...
Please switch to Av mode.
Setting EC to random values...
Setting Flash EC to random values...
Exposure tests completed.


Testing movie recording...
Please switch to Movie mode.
Movie recording tests completed.

Done! 


memory benchmark: https://photos.app.goo.gl/jj2UPSj8ZxCmAaAA2
70D.112

lojzik

70D
magiclantern-lua_fix.2018Jan30.70D112 test

stubtest.log
[Pass] is_play_mode() => 0x1
[Pass] src = fio_malloc(size) => 0x42104084
[Pass] dst = fio_malloc(size) => 0x42908090
[Pass] memcmp(dst, src, 4097) => 0x7d
[Pass] edmac_memcpy(dst, src, 4097) => 0x42908090
[Pass] memcmp(dst, src, 4097) => 0x0
[Pass] edmac_memcpy(dst, src, 4097) => 0x42908090
[Pass] memcmp(dst, src, size) => 0x3
[Pass] edmac_memcpy(dst, src, size) => 0x42908090
[Pass] memcmp(dst, src, size) => 0x0
[Pass] memcmp(dst, src, size) => 0x29
[Pass] edmac_memcpy_start(dst, src, size) => 0x42908090
       dt => 0x182b
[Pass] copied => 0x401870
[Pass] copied => 0x401870
[Pass] copied => 0x401870
[Pass] memcmp(dst, src, copied) => 0x0
[Pass] memcmp(dst, src, copied + 16) => 0xffffffba
       edmac_memcpy_finish()
       free(src)
       free(dst)
Cache test A (EDMAC on BMP buffer)...
[Pass] bmp = bmp_load("ML/CROPMKS/CINESCO2.BMP", 1) => 0x1266a8
[Pass] old => 0x0
[Pass] irq => 0xc0
[Pass] differences => 0x12c0
[Pass] old => 0x0
[Pass] irq => 0xc0
[Pass] differences => 0x0
Cache test B (FIO on 8K buffer)...
[Pass] tries[0] => 0xf8
[Pass] tries[1] => 0xf4
[Pass] tries[2] => 0xf4
[Pass] tries[3] => 0x108
[Pass] failr[0] => 0x75
[Pass] failw[0] => 0xa0
[Pass] failr[1] => 0x6a
[Pass] failw[1] => 0x0
[Pass] failr[2] => 0x0
[Pass] failw[2] => 0xb0
[Pass] failr[3] => 0x0
[Pass] failw[3] => 0x0
       times[0] / tries[0] => 0x2c
       times[1] / tries[1] => 0x31
       times[2] / tries[2] => 0x2d
       times[3] / tries[3] => 0x2d
Cache tests finished.

[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[FAIL] wait_focus_status(1000, 3) => 0x0
[FAIL] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] wait_focus_status(1000, 3) => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x1
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x1
[Pass] get_focus_confirmation() => 0x0
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] lv_focus_status => 0x1
[Pass] f = FIO_CreateFile("test.dat") => 0x6
[Pass] FIO_WriteFile(f, (void*)0xFF000000, 0x10000) => 0x10000
[Pass] FIO_WriteFile(f, (void*)0xFF000000, 0x10000) => 0x10000
       FIO_CloseFile(f)
[Pass] FIO_GetFileSize("test.dat", &size) => 0x0
[Pass] size => 0x20000
[Pass] p = (void*)_alloc_dma_memory(0x20000) => 0x40933b10
[Pass] f = FIO_OpenFile("test.dat", O_RDONLY | O_SYNC) => 0x6
[Pass] FIO_ReadFile(f, p, 0x20000) => 0x20000
       FIO_CloseFile(f)
       _free_dma_memory(p)
[Pass] count => 0x3a98
[Pass] buf = fio_malloc(0x1000000) => 0x42104084
[Pass] FIO_GetFileSize_direct("test.dat") => 0x82000000
[Pass] f = FIO_OpenFile("test.dat", O_RDWR | O_SYNC) => 0x6
[Pass] FIO_SeekSkipFile(f, 0, SEEK_END) => 0x82000000
[Pass] FIO_WriteFile(f, buf, 0x10) => 0x10
[Pass] FIO_SeekSkipFile(f, -0x20, SEEK_END) => 0x81fffff0
[Pass] FIO_WriteFile(f, buf, 0x30) => 0x30
[Pass] FIO_SeekSkipFile(f, 0x20, SEEK_SET) => 0x20
[Pass] FIO_SeekSkipFile(f, 0x30, SEEK_CUR) => 0x50
[Pass] FIO_SeekSkipFile(f, -0x20, SEEK_CUR) => 0x30
[Pass] FIO_GetFileSize_direct("test.dat") => 0x82000020
[Pass] is_file("test.dat") => 0x1
[Pass] FIO_RemoveFile("test.dat") => 0x0
[Pass] is_file("test.dat") => 0x0
[Pass] SetTimerAfter(0, timer_cbr, overrun_cbr, 0) => 0x15
[Pass] timer_func => 0x2
[Pass] SetTimerAfter(1000, timer_cbr, overrun_cbr, 0) => 0xa90e
       msleep(900)
[Pass] timer_func => 0x0
       msleep(200)
[Pass] timer_func => 0x1
[Pass] ABS((timer_time/1000 - t0) - 1000) => 0x2
[Pass] ABS((timer_arg - ta0) - 1000) => 0xa
[Pass] timer = SetTimerAfter(1000, timer_cbr, overrun_cbr, 0) => 0xa96e
       msleep(400)
       CancelTimer(timer)
[Pass] timer_func => 0x0
       msleep(1500)
[Pass] timer_func => 0x0
[Pass] SetHPTimerAfterNow(0, timer_cbr, overrun_cbr, 0) => 0x15
[Pass] timer_func => 0x2
[Pass] SetHPTimerAfterNow(100000, timer_cbr, overrun_cbr, 0) => 0x2d310
       msleep(90)
[Pass] timer_func => 0x0
       msleep(20)
[Pass] timer_func => 0x1
[Pass] ABS(DeltaT(timer_time, t0) - 100000) => 0xf2
[Pass] ABS(DeltaT(timer_arg, ta0) - 100000) => 0xd5
[Pass] ABS((get_us_clock_value() - t0) - 110000) => 0xa6
[Pass] SetHPTimerAfterNow(90000, next_tick_cbr, overrun_cbr, 0) => 0x2d312
       msleep(80)
[Pass] timer_func => 0x0
       msleep(20)
[Pass] timer_func => 0x3
       msleep(80)
[Pass] timer_func => 0x3
       msleep(20)
[Pass] timer_func => 0x1
[Pass] ABS(DeltaT(timer_time, t0) - 300000) => 0x11b
[Pass] ABS(DeltaT(timer_arg, ta0) - 300000) => 0xfc
[Pass] ABS((get_us_clock_value() - t0) - 310000) => 0xb0
       t0 = *(uint32_t*)0xC0242014 => 0x69452
       msleep(250)
       t1 = *(uint32_t*)0xC0242014 => 0xa4c72
[Pass] ABS(MOD(t1-t0, 1048576)/1000 - 250) => 0x7
       LoadCalendarFromRTC( &now )
       s0 = now.tm_sec => 0x1c
       Date/time: 2018/01/30 12:08:28
       msleep(1500)
       LoadCalendarFromRTC( &now )
       s1 = now.tm_sec => 0x1e
[Pass] MOD(s1-s0, 60) => 0x2
[Pass] MOD(s1-s0, 60) => 0x2
       m0 = MALLOC_FREE_MEMORY => 0x37b20
[Pass] p = (void*)_malloc(50*1024) => 0x1283e8
[Pass] CACHEABLE(p) => 0x1283e8
       m1 = MALLOC_FREE_MEMORY => 0x2b310
       _free(p)
       m2 = MALLOC_FREE_MEMORY => 0x37b20
[Pass] ABS((m0-m1) - 50*1024) => 0x10
[Pass] ABS(m0-m2) => 0x0
       m0 = GetFreeMemForAllocateMemory() => 0x257be0
[Pass] p = (void*)_AllocateMemory(256*1024) => 0x933ad0
[Pass] CACHEABLE(p) => 0x933ad0
       m1 = GetFreeMemForAllocateMemory() => 0x217bd4
       _FreeMemory(p)
       m2 = GetFreeMemForAllocateMemory() => 0x257be0
[Pass] ABS((m0-m1) - 256*1024) => 0xc
[Pass] ABS(m0-m2) => 0x0
       m01 = MALLOC_FREE_MEMORY => 0x37b20
       m02 = GetFreeMemForAllocateMemory() => 0x257be0
[Pass] p = (void*)_alloc_dma_memory(256*1024) => 0x40933b10
[Pass] UNCACHEABLE(p) => 0x40933b10
[Pass] CACHEABLE(p) => 0x933b10
[Pass] UNCACHEABLE(CACHEABLE(p)) => 0x40933b10
       _free_dma_memory(p)
[Pass] p = (void*)_shoot_malloc(24*1024*1024) => 0x42104074
[Pass] UNCACHEABLE(p) => 0x42104074
       _shoot_free(p)
       m11 = MALLOC_FREE_MEMORY => 0x37b20
       m12 = GetFreeMemForAllocateMemory() => 0x257b80
[Pass] ABS(m01-m11) => 0x0
[Pass] ABS(m02-m12) => 0x60
[Pass] suite = shoot_malloc_suite_contig(24*1024*1024) => 0x125160
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x1
[Pass] suite->size => 0x1800000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x125188
[Pass] chunk->signature => 'MemChunk'
[Pass] chunk->size => 0x1800000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42104070
[Pass] UNCACHEABLE(p) => 0x42104070
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] suite = shoot_malloc_suite_contig(0) => 0x125160
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x1
[Pass] suite->size => 0x2000000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x125188
[Pass] chunk->signature => 'MemChunk'
[Pass] chunk->size => 0x2000000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42104070
[Pass] UNCACHEABLE(p) => 0x42104070
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] suite = shoot_malloc_suite(64*1024*1024) => 0x125160
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0xa
[Pass] suite->size => 0x4000000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x125188
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x2000000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42104070
[Pass] UNCACHEABLE(p) => 0x42104070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1251e8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x220c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4410407c
[Pass] UNCACHEABLE(p) => 0x4410407c
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125220
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x22f4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x48b140e4
[Pass] UNCACHEABLE(p) => 0x48b140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125258
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x23dc000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x467140e4
[Pass] UNCACHEABLE(p) => 0x467140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125290
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x24c4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5c9140e4
[Pass] UNCACHEABLE(p) => 0x5c9140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1252c8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x25ac000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5a5140e4
[Pass] UNCACHEABLE(p) => 0x5a5140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125300
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x2694000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x581140e4
[Pass] UNCACHEABLE(p) => 0x581140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125338
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x277c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4af140e4
[Pass] UNCACHEABLE(p) => 0x4af140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125370
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x2864000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x443140e4
[Pass] UNCACHEABLE(p) => 0x443140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1253a8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x4000000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x48c00064
[Pass] UNCACHEABLE(p) => 0x48c00064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x0
[Pass] total => 0x4000000
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] suite = shoot_malloc_suite(0) => 0x125160
[Pass] suite->signature => 'MemSuite'
[Pass] suite->num_chunks => 0x14
[Pass] suite->size => 0xf700000
[Pass] chunk = GetFirstChunkFromSuite(suite) => 0x125188
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x2000000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x42104070
[Pass] UNCACHEABLE(p) => 0x42104070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1251e8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x220c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4410407c
[Pass] UNCACHEABLE(p) => 0x4410407c
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125220
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x22f4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x48b140e4
[Pass] UNCACHEABLE(p) => 0x48b140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125258
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x23dc000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x467140e4
[Pass] UNCACHEABLE(p) => 0x467140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125290
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x24c4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5c9140e4
[Pass] UNCACHEABLE(p) => 0x5c9140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1252c8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x25ac000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5a5140e4
[Pass] UNCACHEABLE(p) => 0x5a5140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125300
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x2694000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x581140e4
[Pass] UNCACHEABLE(p) => 0x581140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125338
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x277c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4af140e4
[Pass] UNCACHEABLE(p) => 0x4af140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125370
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x2864000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x443140e4
[Pass] UNCACHEABLE(p) => 0x443140e4
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1253a8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x4864000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x48c00064
[Pass] UNCACHEABLE(p) => 0x48c00064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1253e0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x4b78000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x4ac00070
[Pass] UNCACHEABLE(p) => 0x4ac00070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125418
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x6b78000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x55e00064
[Pass] UNCACHEABLE(p) => 0x55e00064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125450
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x6e8c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x57e00070
[Pass] UNCACHEABLE(p) => 0x57e00070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125488
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x8e8c000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x58200064
[Pass] UNCACHEABLE(p) => 0x58200064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1254c0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0x91a0000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5a200070
[Pass] UNCACHEABLE(p) => 0x5a200070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1254f8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xb1a0000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5a600064
[Pass] UNCACHEABLE(p) => 0x5a600064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125530
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xb4b4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x5c600070
[Pass] UNCACHEABLE(p) => 0x5c600070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x125568
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xd4b4000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x44400064
[Pass] UNCACHEABLE(p) => 0x44400064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1255a0
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xd7c8000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x46400070
[Pass] UNCACHEABLE(p) => 0x46400070
       chunk = GetNextMemoryChunk(suite, chunk) => 0x1255d8
[Pass] chunk->signature => 'MemChunk'
[Pass] total += chunk->size => 0xf700000
[Pass] p = GetMemoryAddressOfMemoryChunk(chunk) => 0x46800064
[Pass] UNCACHEABLE(p) => 0x46800064
       chunk = GetNextMemoryChunk(suite, chunk) => 0x0
[Pass] total => 0xf700000
       shoot_free_suite(suite); suite = 0; chunk = 0;
[Pass] strlen("abc") => 0x3
[Pass] strlen("qwertyuiop") => 0xa
[Pass] strlen("") => 0x0
[Pass] strcpy(msg, "hi there") => 0x1ebeb4
[Pass] msg => 'hi there'
[Pass] snprintf(a, sizeof(a), "foo") => 0x3
[Pass] snprintf(b, sizeof(b), "foo") => 0x3
[Pass] strcmp(a, b) => 0x0
[Pass] snprintf(a, sizeof(a), "bar") => 0x3
[Pass] snprintf(b, sizeof(b), "baz") => 0x3
[Pass] strcmp(a, b) => 0xfffffff8
[Pass] snprintf(a, sizeof(a), "Display") => 0x7
[Pass] snprintf(b, sizeof(b), "Defishing") => 0x9
[Pass] strcmp(a, b) => 0x4
[Pass] snprintf(buf, 3, "%d", 1234) => 0x2
[Pass] buf => '12'
[Pass] memcpy(foo, bar, 6) => 0x1ebe80
[Pass] foo => 'asdfghuiop'
[Pass] memset(bar, '*', 5) => 0x1ebe60
[Pass] bar => '*****hjkl;'
       bzero32(bar + 5, 5)
[Pass] bar => '****'
       EngDrvOut(LCD_Palette[0], 0x1234)
[Pass] shamem_read(LCD_Palette[0]) => 0x1234
       call("TurnOnDisplay")
[Pass] DISPLAY_IS_ON => 0x1
       call("TurnOffDisplay")
[Pass] DISPLAY_IS_ON => 0x0
       call("TurnOnDisplay")
[Pass] DISPLAY_IS_ON => 0x1
       task_create("test", 0x1c, 0x1000, test_task, 0) => 0xdacc00ee
[Pass] test_task_created => 0x1
[Pass] get_current_task_name() => 'run_test'
[Pass] task_max => 0x84
[Pass] task_max => 0x84
[Pass] mq = mq ? mq : (void*)msg_queue_create("test", 5) => 0xdace00c6
[Pass] msg_queue_post(mq, 0x1234567) => 0x0
[Pass] msg_queue_receive(mq, (struct event **) &m, 500) => 0x0
[Pass] m => 0x1234567
[Pass] msg_queue_receive(mq, (struct event **) &m, 500) => 0x9
[Pass] sem = sem ? sem : create_named_semaphore("test", 1) => 0xdad00308
[Pass] take_semaphore(sem, 500) => 0x0
[Pass] take_semaphore(sem, 500) => 0x9
[Pass] give_semaphore(sem) => 0x0
[Pass] take_semaphore(sem, 500) => 0x0
[Pass] give_semaphore(sem) => 0x0
[Pass] rlock = rlock ? rlock : CreateRecursiveLock(0) => 0xdad200de
[Pass] AcquireRecursiveLock(rlock, 500) => 0x0
[Pass] AcquireRecursiveLock(rlock, 500) => 0x0
[Pass] ReleaseRecursiveLock(rlock) => 0x0
[Pass] ReleaseRecursiveLock(rlock) => 0x0
[Pass] ReleaseRecursiveLock(rlock) => 0xf
       SetGUIRequestMode(1); msleep(1000);
[Pass] CURRENT_GUI_MODE => 0x1
       SetGUIRequestMode(2); msleep(1000);
[Pass] CURRENT_GUI_MODE => 0x2
       SetGUIRequestMode(0); msleep(1000);
[Pass] CURRENT_GUI_MODE => 0x0
[Pass] display_idle() => 0x1
       GUI_Control(BGMT_PLAY, 0, 0, 0); msleep(1000);
[Pass] PLAY_MODE => 0x1
[Pass] MENU_MODE => 0x0
       GUI_Control(BGMT_MENU, 0, 0, 0); msleep(1000);
[Pass] MENU_MODE => 0x1
[Pass] PLAY_MODE => 0x0
[Pass] dialog->type => 'DIALOG'
       GUI_Control(BGMT_MENU, 0, 0, 0); msleep(500);
[Pass] MENU_MODE => 0x0
[Pass] PLAY_MODE => 0x0
       SW1(1,100)
[Pass] HALFSHUTTER_PRESSED => 0x1
       SW1(0,100)
[Pass] HALFSHUTTER_PRESSED => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x1
[Pass] is_pure_play_movie_mode() => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x0
[Pass] is_pure_play_movie_mode() => 0x0
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x0
[Pass] is_pure_play_movie_mode() => 0x1
[Pass] is_play_mode() => 0x1
[Pass] is_pure_play_photo_mode() => 0x0
[Pass] is_pure_play_movie_mode() => 0x0
=========================================================
Test complete, 13449 passed, 10 failed.
.


luatest.log
2 tests (problem in first test -> restart)
===============================================================================
ML/SCRIPTS/API_TEST.LUA - 2018-1-30 12:12:52
===============================================================================

Strict mode tests...
Strict mode tests passed.

Generic tests...
arg = table:
  [0] = "API_TEST.LUA"
camera = table:
  shutter = table:
    raw = 0
    apex = -7.
    ms = 0
    value = 0
  aperture = table:
    raw = 32
    apex = 3.
    value = 2.8
    min = table:
      raw = 32
      apex = 3.
      value = 2.8
    max = table:
      raw = 80
      apex = 9.
      value = 22.6
  iso = table:
    raw = 109
    apex = 9.625
    value = 2500
  ec = table:
    raw = 0
    value = 0
  flash_ec = table:
    raw = 0
    value = 0
  kelvin = 6400
  mode = 2
  metering_mode = 3
  drive_mode = 0
  model = "Canon EOS 70D"
  model_short = "70D"
  firmware = "1.1.2"
  temperature = 166
  gui = table:
    menu = false
    play = false
    play_photo = false
    play_movie = false
    qr = false
    idle = true
  reboot = function: p
  wait = function: p
  bulb = function: p
  burst = function: p
  shoot = function: p
event = table:
  pre_shoot = nil
  post_shoot = nil
  shoot_task = nil
  seconds_clock = nil
  keypress = nil
  custom_picture_taking = nil
  intervalometer = nil
  config_save = nil
console = table:
  write = function: p
  show = function: p
  clear = function: p
  hide = function: p
lv = table:
  enabled = false
  paused = false
  running = false
  zoom = 1
  overlays = false
  info = function: p
  wait = function: p
  start = function: p
  resume = function: p
  stop = function: p
  pause = function: p
lens = table:
  name = "EF-S24mm f/2.8 STM"
  focal_length = 24
  focus_distance = 510
  hyperfocal = 10875
  dof_near = 491
  dof_far = 530
  af = true
  af_mode = 0
  focus = function: p
  autofocus = function: p
display = table:
  idle = nil
  height = 480
  width = 720
  on = function: p
  clear = function: p
  rect = function: p
  print = function: p
  line = function: p
  draw = function: p
  circle = function: p
  pixel = function: p
  off = function: p
  load = function: p
  screenshot = function: p
  notify_box = function: p
key = table:
  last = 10
  wait = function: p
  press = function: p
menu = table:
  visible = false
  new = function: p
  block = function: p
  get = function: p
  select = function: p
  close = function: p
  set = function: p
  open = function: p
movie = table:
  recording = false
  start = function: p
  stop = function: p
dryos = table:
  clock = 143
  ms_clock = 143540
  image_prefix = "IMG_"
  dcim_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "B:/DCIM/"
    path = "B:/DCIM/100CANON/"
  config_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "ML/"
    path = "ML/SETTINGS/"
  ml_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 4639
    folder_number = 100
    free_space = 15569184
    type = "SD"
    path = "B:/"
    _card_ptr = userdata
  shooting_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 4639
    folder_number = 100
    free_space = 15569184
    type = "SD"
    path = "B:/"
    _card_ptr = userdata
  date = table:
    year = 2018
    isdst = false
    sec = 53
    day = 30
    wday = 3
    yday = 30
    min = 12
    month = 1
    hour = 12
  directory = function: p
  remove = function: p
  rename = function: p
  call = function: p
interval = table:
  time = 10
  count = 0
  running = false
  stop = function: p
battery = table:
  level = 35
  id = 1
  performance = 0
  time = nil
  drain_rate = 20
task = table:
  create = function: p
  yield = function: p
property = table:
Generic tests completed.

Module tests...
Testing file I/O...
Copy test: autoexec.bin -> tmp.bin
Copy test OK
Append test: tmp.txt
Append test OK
Rename test: apple.txt -> banana.txt
Rename test OK
Rename test: apple.txt -> ML/banana.txt
Rename test OK
File I/O tests completed.

Testing Canon GUI functions...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Resume LiveView...
Pause LiveView...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Start LiveView...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Resume LiveView...
Pause LiveView...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter MENU mode...
Exit MENU mode...
Pause LiveView...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Enter MENU mode...
Canon GUI tests completed.

Testing ML menu API...
Menu tests completed.

Testing picture taking functions...
Please switch to M mode.
Snap simulation test...
Single picture...
B:/DCIM/100CANON/IMG_4640.CR2: 28472807
B:/DCIM/100CANON/IMG_4640.JPG not found.
Two burst pictures...
Ideally, the camera should be in some continuous shooting mode (not checked).
B:/DCIM/100CANON/ABC_4641.CR2: 28475751
B:/DCIM/100CANON/ABC_4641.JPG not found.
B:/DCIM/100CANON/ABC_4642.CR2: 28475684
B:/DCIM/100CANON/ABC_4642.JPG not found.
Bracketed pictures...
B:/DCIM/100CANON/IMG_4643.CR2: 25995871
B:/DCIM/100CANON/IMG_4643.JPG not found.
B:/DCIM/100CANON/IMG_4644.CR2: 28478890
B:/DCIM/100CANON/IMG_4644.JPG not found.
B:/DCIM/100CANON/IMG_4645.CR2: 19046998
B:/DCIM/100CANON/IMG_4645.JPG not found.
Bulb picture...
Elapsed time: 13090
B:/DCIM/100CANON/IMG_4646.CR2: 14474791
B:/DCIM/100CANON/IMG_4646.JPG not found.
Picture taking tests completed.

Testing multitasking...
Only one task allowed to interrupt...
Main task yielding.
Main task yielding.
Task C started.
Task C finished.

===============================================================================
ML/SCRIPTS/API_TEST.LUA - 2018-1-30 12:22:20
===============================================================================

Strict mode tests...
Strict mode tests passed.

Generic tests...
arg = table:
  [0] = "API_TEST.LUA"
camera = table:
  shutter = table:
    raw = 75
    apex = 2.375
    ms = 193
    value = 0.192776
  aperture = table:
    raw = 32
    apex = 3.
    value = 2.8
    min = table:
      raw = 32
      apex = 3.
      value = 2.8
    max = table:
      raw = 80
      apex = 9.
      value = 22.6
  iso = table:
    raw = 104
    apex = 9.
    value = 1600
  ec = table:
    raw = 0
    value = 0
  flash_ec = table:
    raw = 0
    value = 0
  kelvin = 6400
  mode = 3
  metering_mode = 3
  drive_mode = 0
  model = "Canon EOS 70D"
  model_short = "70D"
  firmware = "1.1.2"
  temperature = 185
  gui = table:
    menu = false
    play = false
    play_photo = false
    play_movie = false
    qr = false
    idle = true
  wait = function: p
  bulb = function: p
  reboot = function: p
  burst = function: p
  shoot = function: p
event = table:
  pre_shoot = nil
  post_shoot = nil
  shoot_task = nil
  seconds_clock = nil
  keypress = nil
  custom_picture_taking = nil
  intervalometer = nil
  config_save = nil
console = table:
  hide = function: p
  write = function: p
  clear = function: p
  show = function: p
lv = table:
  enabled = false
  paused = false
  running = false
  zoom = 1
  overlays = false
  pause = function: p
  resume = function: p
  info = function: p
  wait = function: p
  start = function: p
  stop = function: p
lens = table:
  name = "EF-S24mm f/2.8 STM"
  focal_length = 0
  focus_distance = 90
  hyperfocal = 0
  dof_near = 0
  dof_far = 0
  af = true
  af_mode = 0
  autofocus = function: p
  focus = function: p
display = table:
  idle = nil
  height = 480
  width = 720
  on = function: p
  line = function: p
  pixel = function: p
  load = function: p
  rect = function: p
  off = function: p
  circle = function: p
  draw = function: p
  notify_box = function: p
  print = function: p
  screenshot = function: p
  clear = function: p
key = table:
  last = 10
  wait = function: p
  press = function: p
menu = table:
  visible = false
  open = function: p
  get = function: p
  close = function: p
  new = function: p
  set = function: p
  block = function: p
  select = function: p
movie = table:
  recording = false
  start = function: p
  stop = function: p
dryos = table:
  clock = 17
  ms_clock = 17424
  image_prefix = "IMG_"
  dcim_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "B:/DCIM/"
    path = "B:/DCIM/100CANON/"
  config_dir = table:
    exists = true
    create = function: p
    children = function: p
    files = function: p
    parent = table:
      exists = true
      create = function: p
      children = function: p
      files = function: p
      parent = table:
        exists = true
        create = function: p
        children = function: p
        files = function: p
        parent = nil
        path = "B:/"
      path = "ML/"
    path = "ML/SETTINGS/"
  ml_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 4646
    folder_number = 100
    free_space = 15399648
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  shooting_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 4646
    folder_number = 100
    free_space = 15399648
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  date = table:
    year = 2018
    day = 30
    wday = 3
    isdst = false
    yday = 30
    min = 22
    hour = 12
    month = 1
    sec = 21
  directory = function: p
  rename = function: p
  remove = function: p
  call = function: p
interval = table:
  time = 10
  count = 0
  running = false
  stop = function: p
battery = table:
  level = 29
  id = 1
  performance = 0
  time = nil
  drain_rate = 52
task = table:
  yield = function: p
  create = function: p
property = table:
Generic tests completed.

Module tests...
Testing file I/O...
Copy test: autoexec.bin -> tmp.bin
Copy test OK
Append test: tmp.txt
Append test OK
Rename test: apple.txt -> banana.txt
Rename test OK
Rename test: apple.txt -> ML/banana.txt
Rename test OK
File I/O tests completed.

Testing Canon GUI functions...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Enter MENU mode...
Exit MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Pause LiveView...
Resume LiveView...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Exit PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Exit MENU mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Enter MENU mode...
Enter PLAY mode...
Exit PLAY mode...
Stop LiveView...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Start LiveView...
Enter PLAY mode...
Exit PLAY mode...
Pause LiveView...
Enter PLAY mode...
Enter MENU mode...
Enter PLAY mode...
Enter PLAY mode...
Enter MENU mode...
Exit MENU mode...
Stop LiveView...
Enter PLAY mode...
Canon GUI tests completed.

Testing ML menu API...
Menu tests completed.

Testing picture taking functions...
Snap simulation test...
Single picture...
B:/DCIM/100CANON/IMG_4647.CR2: 27102597
B:/DCIM/100CANON/IMG_4647.JPG not found.
Two burst pictures...
Ideally, the camera should be in some continuous shooting mode (not checked).
B:/DCIM/100CANON/ABC_4648.CR2: 27100107
B:/DCIM/100CANON/ABC_4648.JPG not found.
B:/DCIM/100CANON/ABC_4649.CR2: 27095704
B:/DCIM/100CANON/ABC_4649.JPG not found.
Bracketed pictures...
B:/DCIM/100CANON/IMG_4650.CR2: 25252101
B:/DCIM/100CANON/IMG_4650.JPG not found.
B:/DCIM/100CANON/IMG_4651.CR2: 27074924
B:/DCIM/100CANON/IMG_4651.JPG not found.
B:/DCIM/100CANON/IMG_4652.CR2: 18521940
B:/DCIM/100CANON/IMG_4652.JPG not found.
Bulb picture...
Elapsed time: 12664
B:/DCIM/100CANON/IMG_4653.CR2: 14477602
B:/DCIM/100CANON/IMG_4653.JPG not found.
Picture taking tests completed.

Testing multitasking...
Only one task allowed to interrupt...
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Main task yielding.
Task C started.
Task C finished.
Main task back.
Multitasking tests completed.

Testing half-shutter...
Half-shutter test OK.

Testing module 'lv'...
Starting LiveView...
Overlays: Canon
Overlays: Canon
Overlays: Canon
Overlays: Canon
Overlays: ML
Overlays: ML
Overlays: disabled
Overlays: Canon
Overlays: Canon
Overlays: Canon
Overlays: Canon
Overlays: disabled
Overlays: ML
Overlays: disabled
Overlays: ML
Setting zoom to x1...
Setting zoom to x5...
Setting zoom to x10...
Setting zoom to x5...
Setting zoom to x1...
Setting zoom to x10...
Setting zoom to x1...
Pausing LiveView...
Resuming LiveView...
Stopping LiveView...
LiveView tests completed.


Testing lens focus functionality...
Autofocus outside LiveView...
Focus distance: 510
Autofocus in LiveView...
Please trigger autofocus (half-shutter / AF-ON / * ).
19...18...17...16...15...14...13...12...Autofocus triggered.
Autofocus completed.
Focus distance: 410
Focusing backward...
Focus distance: 655350
Focus motor position: 1824
Focusing forward with step size 3, wait=true...
....................
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 3, wait=true...
...................
Focus distance: 655350
Focus motor position: 1824
Focus range: 20 steps forward, 19 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.
Focusing forward with step size 3, wait=false...
...............................................
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 3, wait=false...
................................................
Focus distance: 655350
Focus motor position: 1824
Focus range: 47 steps forward, 48 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.
Focusing forward with step size 2, wait=true...
...
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 2, wait=true...
...
Focus distance: 655350
Focus motor position: 1824
Focus range: 128 steps forward, 127 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.
Focusing forward with step size 2, wait=false...
...
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 2, wait=false...
...
Focus distance: 655350
Focus motor position: 1824
Focus range: 152 steps forward, 150 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.
Focusing forward with step size 1, wait=true...
...
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 1, wait=true...
...
Focus distance: 655350
Focus motor position: 1824
Focus range: 457 steps forward, 457 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.
Focusing forward with step size 1, wait=false...
...
Focus distance: 160
Focus motor position: 290
Focusing backward with step size 1, wait=false...
...
Focus distance: 655350
Focus motor position: 1824
Focus range: 469 steps forward, 470 steps backward.
Motor steps: 1534 forward, 1534 backward, 0 lost.

Focus test completed.

Testing exposure settings...
Camera    : Canon EOS 70D (70D) 1.1.2
Lens      : EF-S24mm f/2.8 STM
Shoot mode: 3
Shutter   : ,5 (raw 75, 0.192776s, 193ms, apex 2.375)
Aperture  : 2.8 (raw 32, f/2.8, apex 3.)
Av range  : 2.8..22 (raw 32..80, f/2.8..f/22.6, apex 3...9.)
ISO       : €1600 (raw 104, 1600, apex 9.)
EC        : 0.0 (raw 0, 0 EV)
Flash EC  : 0.0 (raw 0, 0 EV)
Setting shutter to random values...
Setting ISO to random values...
Setting aperture to random values...
Please switch to Av mode.
Setting EC to random values...
Setting Flash EC to random values...
Exposure tests completed.


Testing movie recording...
Please switch to Movie mode.
Movie recording tests completed.

Done!

70D.112

aprofiti

I noticed a strange behavior of umm_alloc while working on a modified version of "config.lua" which use recursion to traverse submenus and is used by a complex script:

I believe that memory isn't free when a local variable is declared inside a function or a large number of function call occurs.

So I decided to reproduce on a simple script:
-- Test umm_malloc heap
--
local num = 100000

--function property.LENS_NAME:handler(value)
--end

function testHeap()
  local t = {"1","2","3","4","5"}
  return t
end

for i=0, num, 1 do
  testHeap()
end

This one free heap correctly when ending.

But if I add a property.LENS_NAME:handler(value) to make it a complex script, I get:

num = 1000   -> free umm_heap: 236KB
num = 10000 -> free umm_heap: 222KB

Here I get always the same values when rebooting the camera, instead I noticied in the other script that some times umm_heap was 156KB and sometimes up to 222KB.

Is this a normal behavior or is there something to check inside the backend?

a1ex

Tried calling collectgarbage() after the loop => 242KB after 10000 and 1000000 iterations.

I'm not sure when it runs (maybe dmilligan already knows without googling), but looks like we can call it at the end of the initialization stage of a "complex" script:: https://stackoverflow.com/questions/18273123/run-garbage-collector

Also found an interesting example here: http://luatut.com/collectgarbage.html

With this:

collectgarbage('stop')
for i=0, num, 1 do
  testHeap()
end
print(collectgarbage('count'))
collectgarbage('restart')


I've got 175K after 10000 iterations and 5.5K after 100000, with a malloc error in the Debug menu (1100D, QEMU). That's a good test for exercising the general-purpose memory backend in ML (which is used when the umm buffer gets full). From this test, my conclusion is that garbage collection gets done during that loop, just we don't know when it happens exactly (it's certainly not done after the last iteration).

dmilligan

If the Lua garbage collector is anything like other collectors I'm more familiar with, it likely uses some sort of heuristic to decide when to run. The goal being to optimize the trade off between running too often which would hurt performance and not running often enough which would leave unused memory unreclaimed for longer. If that's the case (I don't have any specific experience with the lua garbage collector), the heuristic is probably tuned for systems that have more free memory than we do. If it's a real problem, you could try adjusting it to running more often (IDK how or where to do that), but if it's just something you noticed, but is not causing issues, I would leave it alone.