ML on EOS-M2

[a1ex]

Generic stuff: if it interferes with some Canon feature (such as, not being able to capture images, or unexplained crashes or whatever), and you have no idea where to start looking, try going back to Hello World (i.e. no user tasks started). Did that work? Narrow down by not starting some of our tasks (trial and error). Found the task? Narrow down there (avoid executing all the stuff).

Does it work after disabling the task dispatch hook? Likely some important GUI event gets blocked (incorrectly) by our code. Find out which one (again, trial and error - maybe by commenting out some or all event handlers in gui-common.c). Still no luck? Use only our GUI task, without calling any of our event handlers - take the "if (magic_is_off())" code path in gui.c. Once it's working, start enabling things to see where it breaks.

Shutter not displayed correctly? Find out where it's displayed (look for strings) -> in movie mode, this will use get_current_shutter_reciprocal_x1000. There you'll get a couple of methods - ideally it should be read directly from ADTG registers, as this value is used to configure the hardware, and likely to be the most accurate value we can get; the others are just guesswork for models where this doesn't work yet (todo: remove them, maybe keep the others only as documentation). Double check the stubs / consts used by that code.

[dfort]

Just a few quick tests.

Hello World works fine in both minimal builds and regular builds.

Not sure how not to start tasks or where the task list is located but I did comment out some of the features in all_features.h and found out that without FEATURE_GLOBAL_DRAW the camera will shoot stills and record H.264. Same thing with commenting out "task_dispatch_hook = my_task_dispatch_hook;" in boot-hack.c but then I couldn't get into the ML menu.

One baby step I took was finding this:

Code: [Select]

SRM_BUFFER_SIZE 0x1F24000
That reminds me--shouldn't all of the known SRM_BUFFER_SIZE values be entered into the crop_rec_4k branch? I believe we have values for all cameras but they are spread out all over various forum posts.

[EDIT] Maybe these screenshots of the Debug "Show tasks" screens might help?

[dfort]

Took another look in consts.h and one thing that was questionable was the values of YUV422_LV_BUFFER_1,2,3. One of the buffers was found in QEMU but is this buffer 1, 2 or 3? The buffers on other Digic 5 cameras are spaced 0x410000 apart so I did this.

Code: [Select]

// Started out by using the one found value (0x4f3d7800)for all three as a workaround
// then adding 0x410000 to determine the other two.
// http://www.magiclantern.fm/forum/index.php?topic=15895.msg186493#msg186493
#define YUV422_LV_BUFFER_1 0x4F3D7800
#define YUV422_LV_BUFFER_2 0x4F7E7800
#define YUV422_LV_BUFFER_3 0x4FBF7800

Is this correct? First I checked to see if something obvious happens if I just put in bogus values. Yes, the histogram stops working. Next I tired each of the addresses for all of the buffers and they all worked. That is, the histogram worked. Finally, I took the address that was found, subtracted 0x410000 and the histogram stopped working. So now I'm pretty sure these are correct, but what about the order? Does that make any difference? The EOSM has the buffer addresses listed in ascending order (1,2,3) but what about the other cameras?

Code: [Select]

EOSM    1,2,3
700D    2,1,3
6D      2,3,1
650D    2,1,3
100D    2,1,3
5D3.113 1,2,3
5D3.123 3,2,1,4 (quad buffered)
Searching the forum I found this post and this one that talks about YUV422_LV_BUFFER and it looks like the first buffer is treated differently from the other two.

This didn't bring me any closer to resolving the issues that currently plague the EOSM2 but thought these observations were curious enough to post.

[dfort]

I kept going over and over the stubs and it seemed like they were correct. One thing I did to make it easier to find in the disassembly was to write some of them like this:

Code: [Select]

#define CURRENT_GUI_MODE (*(int*)(0x92860+0x5C)) // in SetGUIRequestMode

This shouldn't make a difference but it allowed the lua test to complete instead of getting stuck when it tried to switch to LiveView.

Code: [Select]

#define CURRENT_GUI_MODE (*(int*)0x928BC) // in SetGUIRequestMode (0x92860+0x5C)

Here is the first complete lua api test:

Code: [Select]

===============================================================================
ML/SCRIPTS/API_TEST.LUA - 2018-2-6 11:20:00
===============================================================================

Strict mode tests...
Strict mode tests passed.

Generic tests...
camera = table:
  shutter = table:
    raw = 96
    apex = 5
    ms = 31
    value = 0.03125
  aperture = table:
    raw = 40
    apex = 4
    value = 4
    min = table:
      raw = 24
      apex = 2
      value = 2
    max = table:
      raw = 80
      apex = 9
      value = 22.6
  iso = table:
    raw = 72
    apex = 5
    value = 100
  ec = table:
    raw = 0
    value = 0
  flash_ec = table:
    raw = 0
    value = 0
  kelvin = 6500
  mode = 20
  metering_mode = 5
  drive_mode = 0
  model = "Canon EOS M2"
  model_short = "EOSM2"
  firmware = "1.0.3"
  temperature = 196
  state = 0
  shoot = function: p
  bulb = function: p
  reboot = 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
  hide = function: p
  clear = function: p
  show = function: p
lv = table:
  enabled = true
  paused = false
  running = true
  zoom = 1
  pause = function: p
  stop = function: p
  start = function: p
  resume = function: p
  wait = function: p
  info = function: p
lens = table:
  name = "EF-M22mm f/2 STM"
  focal_length = 22
  focus_distance = 190
  hyperfocal = 6412
  dof_near = 186
  dof_far = 193
  af = true
  af_mode = 0
  focus = function: p
display = table:
  idle = false
  height = 480
  width = 720
  line = function: p
  circle = function: p
  on = function: p
  off = function: p
  load = function: p
  clear = function: p
  notify_box = function: p
  rect = function: p
  draw = function: p
  pixel = function: p
  screenshot = function: p
  print = function: p
key = table:
  last = 0
  press = function: p
  wait = function: p
menu = table:
  visible = false
  new = function: p
  block = function: p
  set = function: p
  open = function: p
  get = function: p
  close = function: p
testmenu = userdata:
  value = 0
  name = "Script API tests"
  help = "Various tests for the Lua scripting API."
  help2 = "When adding new Lua APIs, tests for them should go here."
  advanced = 0
  depends_on = 0
  edit_mode = 0
  hidden = false
  icon_type = 5
  jhidden = false
  max = 0
  min = 0
  selected = true
  shidden = false
  starred = false
  submenu_height = 0
  submenu_width = 0
  unit = 0
  works_best_in = 0
  run_in_separate_task = 0
  select = function: p
  update = nil
  info = nil
  rinfo = nil
  warning = nil
movie = table:
  recording = false
  stop = function: p
  start = function: p
dryos = table:
  clock = 20
  ms_clock = 20650
  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 = 7211
    folder_number = 100
    free_space = 31112864
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  shooting_card = table:
    cluster_size = 32768
    drive_letter = "B"
    file_number = 7211
    folder_number = 100
    free_space = 31112864
    type = "SD"
    _card_ptr = userdata
    path = "B:/"
  date = table:
    sec = 2
    min = 20
    month = 2
    yday = 37
    isdst = false
    hour = 11
    day = 6
    year = 2018
    wday = 3
  call = function: p
  remove = function: p
  directory = function: p
interval = table:
  time = 10
  count = 0
  running = 0
  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:30: in function <ML/SCRIPTS/API_TEST.LUA:29>
[C]: in function 'xpcall'
ML/SCRIPTS/API_TEST.LUA:29: in function 'print_table'
ML/SCRIPTS/API_TEST.LUA:75: in function 'generic_tests'
ML/SCRIPTS/API_TEST.LUA:634: in function 'api_tests'task = table:
  yield = function: p
  create = function: p
property = table:
Generic tests completed.

Module tests...
Copy test: autoexec.bin -> tmp.bin
Copy test OK
Append test: tmp.txt
Append test OK
Testing exposure settings, module 'camera'...
Camera    : Canon EOS M2 (EOSM2) 1.0.3
Lens      : EF-M22mm f/2 STM
Shoot mode: 20
Shutter   : Ç30 (raw 96, 0.03125s, 31ms, apex 5)
Aperture  : Å4.0 (raw 40, f/4, apex 4)
Av range  : Å2.0..Å22 (raw 24..80, f/2..f/22.6, apex 2..9)
ISO       : 100 (raw 72, 100, apex 5)
EC        : 0.0 (raw 0, 0 EV)
Flash EC  : 0.0 (raw 0, 0 EV)
Please switch to M mode.
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 module 'lv'...
Starting LiveView...
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.

Focus distance: 170
Focusing backward...
Focus distance: 655350
Focusing forward with step size 3, wait=true...
...
Focus distance: 140
Focusing backward with step size 3, wait=true...
................
Focus distance: 655350
Focus range: 173 steps forward, 16 steps backward.
Focusing forward with step size 3, wait=false...
...
Focus distance: 655350
Focusing backward with step size 3, wait=false...

Focus distance: 655350
Focus range: 3 steps forward, 0 steps backward.
Focusing forward with step size 2, wait=true...

Focus distance: 655350
Focusing backward with step size 2, wait=true...

Focus distance: 655350
Focus range: 0 steps forward, 0 steps backward.
Focusing forward with step size 2, wait=false...

Focus distance: 655350
Focusing backward with step size 2, wait=false...

Focus distance: 655350
Focus range: 0 steps forward, 0 steps backward.
Focusing forward with step size 1, wait=true...

Focus distance: 655350
Focusing backward with step size 1, wait=true...

Focus distance: 655350
Focus range: 0 steps forward, 0 steps backward.
Focusing forward with step size 1, wait=false...

Focus distance: 655350
Focusing backward with step size 1, wait=false...

Focus distance: 655350
Focus range: 0 steps forward, 0 steps backward.
Focus test completed.

Done!


[dfort]

More tinkering without resolving anything.

The shutter speed / shutter angle display issue seems to be pointing to a problem here:

platform/EOSM2.103/consts.h

Code: [Select]

#define VIDEO_PARAMETERS_SRC_3 MEM(0x91CD4) // (0x91CC8+0xC)
#define FRAME_ISO (*(uint8_t*)(VIDEO_PARAMETERS_SRC_3+0))
#define FRAME_APERTURE (*(uint8_t*)(VIDEO_PARAMETERS_SRC_3+1))
#define FRAME_SHUTTER (*(uint8_t*)(VIDEO_PARAMETERS_SRC_3+2))
#define FRAME_SHUTTER_TIMER (*(uint16_t*)(VIDEO_PARAMETERS_SRC_3+6))
#define FRAME_BV ((int)FRAME_SHUTTER + (int)FRAME_APERTURE - (int)FRAME_ISO)

I'm pretty sure the VIDEO_PARAMETERS_SRC_3 is correct. I printed it out using this:

Code: [Select]

NotifyBox(10000, "VIDEO_PARAMETERS_SRC_3 0x%x", VIDEO_PARAMETERS_SRC_3);

And got 0x6FEC3C. So, that should be the FRAME_ISO, next is the FRAME_APERTURE at 0x6FEC3D, etc... Now how to verify that it is working properly? IDK. The 5D3 uses the same method to find VIDEO_PARAMETERS_SRC_3 but the constants are offset by different amounts. Since I was willing to try anything I used the offsets from the 5D3 and got the same (wrong) results for the shutter speed and correct shutter angle when the camera is in movie mode. Figured how to get it to use the "fallback to APEX units" method in src/fps-engio.c and it displayed the right shutter speed but the wrong shutter angle. Ugh.

In my previous post I was able to get the lua api test working but it didn't resolve the issue of the ML overlays disappearing and getting the "Raw error, falling back to YUV overlays" error message when taking a picture.

Oh yeah, no audio meters either. Still not ready for testers--unless someone wants to see their EOSM2 print "Hello World" on the screen.

[pureaxis]

Registered to voice support! Eagerly awaiting release! 

[dfort]

Got the adtg_gui module working so I thought I'd try finding the values needed for Dual ISO. It was fairly easy to check the registers on the 700D but on the EOSM and EOSM2 I can't seem to be able to get into photo mode. Is there any way to show "ShootCapture" in adtg_gui on these cameras?

[a1ex]

There is an option to disable logging in LiveView (Advanced menu); IIRC it was written with the EOS M in mind.

[dfort]

Thanks -- found that the disable logging feature is in the iso-research branch version of adtg_gui. It took me several tries to get the EOSM2 working on that branch but I did it. Well, it sort of works. Taking a still photo will reboot the camera. Haven't figured that one out. Managed to to get FRSP working just enough to find the address needed for dual_iso PHOTO_CMOS_ISO_START but the DNG was ng.

Still very much a work in progress but it has started sprouting branches!

[EDIT] When taking a still photo it sometimes reboots the camera, crashes or the ML overlays don't return. In all cases it shows the "Raw error, falling back to YUV overlays" message but no log file is saved. Any hints on where to start looking for this issue?

[a1ex]

The reason for "raw error" messages is printed to the console if you enable RAW_DEBUG in raw.c (maybe some more of these messages should be printed by default). There are a few possible reasons for this error.

[dfort]

Thanks, I'll check into that.

One thing I've been trying is to vary these values and was able to change the time between starting the camera and LiveView freezing.

platform/EOSM2.103/include/platform/state-object.h

Code: [Select]

#define DISPLAY_STATE DISPLAY_STATEOBJ
#define INPUT_SET_IMAGE_VRAM_PARAMETER_MUTE_FLIP_CBR 23 // need to verify
#define INPUT_ENABLE_IMAGE_PHYSICAL_SCREEN_PARAMETER 24 // need to verify

Searched but couldn't find anything that explains how to set these values.

[dfort]

Ok, did this:

Code: [Select]

#define RAW_DEBUG        /* define it to help with porting */

and when taking a still photo with the console open it doesn't print any debug information but when I closed the console and shot another still it opened the console and printed:

Code: [Select]

...
Modules loaded
Save configs . . .
Save configs . . .
raw update update from lv_playback
Photo raw size error
Note that the message won't print if the console is already open. It needs to be closed in order to get this message. Restarting the camera it prints this:

Code: [Select]

...
Modules loaded
raw update from livev_hiprio_task
LV RAW size too small
raw update from livev_hiprio_task
LV RAW size too small
...
That message is repeated 5 times.

Searched for livev_hiprio_task and found it in zebras.c so I tried it again with Zebras turned off and got the same results. Turned off Global Draw and no debug messages. Though that's maybe because the console doesn't show up if Global Draw is off?

[dfort]

Did some more debugging. Added this line to see what is going on.

Code: [Select]

        /* the raw edmac might be used by something else, and wrong numbers may be still there */
        /* e.g. 5D2: 1244x1, obviously wrong */
        if (width < 320 || height < 160)
        {
            dbg_printf("LV RAW size too small\n");
+           dbg_printf("width x height = %d x %d\n", width,height);
            return 0;
        }

Looks like the height is ok but the width is way off:

Code: [Select]

raw update from livev_hiprio_task
LV RAW size too small
width x height = -16 x 727

[a1ex]

This one is puzzling. Does the code actually read registers 0xC0F06800 and 0xC0F06804? (from what I could tell from the source, it should). Can you print the raw values of top_left and bot_right?

The 727 was manually set, so the code followed the top half (CONFIG_EDMAC_RAW_SLURP) of raw_lv_get_resolution. The above registers appear to be set to expected values in Canon code (e.g. 0x10013 and 0x4A701D7 near A8468, sub_62BD0 => 1808x1190). Are they overwritten anywhere else? (adtg_gui and io_trace should be able to tell). Does anything in ML code interfere? Try reading them from the minimal codebase.

Code: [Select]

uint32_t top_left  = shamem_read(0xC0F06800);
uint32_t bot_right = shamem_read(0xC0F06804);
char msg[64];
snprintf(msg, sizeof(msg), "%x %x", top_left, bot_right); // copy it from stdio.c
font_draw(..., msg);   


[dfort]

One step at a time:

Can you print the raw values of top_left and bot_right?

EOSM2.103

Code: [Select]

top_left = 4
bot_right = 0

width x height = -16 x 727
This can't be right. Checking the original:

EOSM.202

Code: [Select]

top_left = 65552
bot_right = 77988308

width x height = 1808 x 1189
Interesting, that's the mv1080 buffer size for the EOSM.

[dfort]

Think I stumbled on the next step.

Copied the snprintf code from stdio.c and put it into src/minimal.c then I did this:

Code: [Select]

static int
my_init_task(int a, int b, int c, int d)
{
    init_task(a,b,c,d);
   
    /* wait for display to initialize */
    while (!bmp_vram_info[1].vram2)
    {
        msleep(100);
    }

    while(1)
    {
        MEM(CARD_LED_ADDRESS) = LEDON;
        msleep(500);
        MEM(CARD_LED_ADDRESS) = LEDOFF;
        msleep(500);
       
//        font_draw(100, 75, COLOR_WHITE, 3, "Hello, World!");

        uint32_t top_left  = shamem_read(0xC0F06800);
        uint32_t bot_right = shamem_read(0xC0F06804);
        char msg[64];
        snprintf(msg, sizeof(msg), "%x %x", top_left, bot_right); // copy it from stdio.c
        font_draw(100, 75, COLOR_WHITE, 3, msg);   

    }
   
    return 0;
}

Compiled from the minimal/EOSM2 directory.

I had to shoot a video of the screen to see what was going on. At startup it would show "1 40020000" then it would write over the 1 and the 4 without clearing the screen so the numbers are superimposed and illegible. When turning off the camera it would show "4 0" so perhaps that's what was superimposed?

Ran the same test on the EOSM and it displayed "10010 4a601d4" without superimposing any other value over it so maybe I did run the test properly? This matches the decimal values for the top_left = 65552 bot_right = 77988308 found on the previous test.

[a1ex]

Okay, somebody (some Canon code) must be overwriting the value; adtg_gui can tell what happened, but it requires some fiddling (it won't do so out of the box - too many registers out there); a better tool for diagnosing this would be io_trace (monitored range: 0xC0F06000, 0x1000).

[dfort]

Startup log with io-trace monitored range: 0xC0F06000, 0x1000

https://pastebin.com/jEzAy9cv

Hope this works. The EOSM2 needs to be started in "Play" mode. Normal startup in LV will not boot and no log is saved.

Makefile.user

Code: [Select]

CONFIG_DEBUG_INTERCEPT_STARTUP = y
CONFIG_MMIO_TRACE=y

[EDIT] Saved another startup log. This time starting the camera in "Play" mode and immediately switching to LV using a half-shutter press. Log looks different but I don't see any C0F06800 or C0F06804 events.

https://pastebin.com/1Tjieg03

[EDIT 2] Discovered there was a second log saved when the camera switched from Play to LV--still no C0F06800 or C0F06804 events.

https://pastebin.com/06LvGwxu

[EDIT 3] Just realized that I didn't save the changed to io_trace.c so I ran another startup log.

https://pastebin.com/4JT7uF9T

Code: [Select]

static ASM_VAR uint32_t protected_region = REGION(0xC0F06000, 0x1000);

[a1ex]

All these logs show the GPIO range. The log has to be captured in LiveView; otherwise it won't be useful. Starting from PLAY mode is OK as long as it also goes to LiveView. Starting from LiveView may or may not be useful, depending on where this register is set. Starting into a video mode with lower FPS may help (don't start into 60p).

Lock-ups are hard to debug - some hints here.

The io_trace_full branch might also help, but for small ranges like this, I wouldn't expect major improvements.

[dfort]

Ok -- let's start with a clean slate. Merged EOSM2 into the io_trace_full branch and made sure to save the changes to monitored range: 0xC0F06000, 0x1000. This time I started in 1080/24 movie mode in LV and waited a long time, it never completed startup but it did save a couple of startup logs:

DM-0000.LOG DM-0001.LOG

[a1ex]

Comment out all the "extra" stuff (calls to dm_spy_extra_install/uninstall) and only record a small subset of the messages (for example, those starting with 'e' from 'evf'). The default set is too verbose to cover the entire LiveView startup (and the overhead of all these messages might be too large). Also, keep in mind CONFIG_DEBUG_INTERCEPT_STARTUP is not compatible with CONFIG_MMIO_TRACE in the io_trace_full branch (the main reason it's yet another branch). Only plain CONFIG_DEBUG_INTERCEPT works there (with manual selection from menu).

The message filtering is done in my_DebugMsg, somewhere at the beginning:

Code: [Select]

    if (fmt[0] != 'e') return;

You could also write small test sequences, such as:

Code: [Select]

static void run_test()
{
    msleep(1000);
    SetGUIRequestMode(GUIMODE_PLAY); // go to PLAY mode
    msleep(1000);
    debug_intercept();     // start logging
    SetGUIRequestMode(0);  // back to LiveView
    msleep(1000);
    debug_intercept();     // stop logging
}


[dfort]

Followed your instructions and also added:

debug.c

Code: [Select]

#include "dm-spy.h"
but I'm getting:

Code: [Select]

[ LD       ]   magiclantern
debug.o: In function `run_test':
/Users/rosiefort/magic-lantern/platform/EOSM2.103/../../src/debug.c:290: undefined reference to `debug_intercept'
/Users/rosiefort/magic-lantern/platform/EOSM2.103/../../src/debug.c:293: undefined reference to `debug_intercept'
io_trace.o: In function `io_trace_log_message':
/Users/rosiefort/magic-lantern/platform/EOSM2.103/../../src/io_trace.c:451: undefined reference to `debug_format_msg'
make: *** [magiclantern] Error 1

debug_intercept and debug_format_msg are defined in dm-spy.h. io_trace.c already includes dm-spy.h

Can't seem to be able to get past this.

[EDIT] Never mind -- only "CONFIG_DEBUG_INTERCEPT = y" is compatible with this, right? I had "CONFIG_DEBUGMSG = y" selected by mistake.

[a1ex]

CONFIG_DEBUG_INTERCEPT=y and CONFIG_MMIO_TRACE=y in Makefile.user? Also, make clean?

[dfort]

I was almost ready to give up but finally got it running. I couldn't get into the ML menus in movie mode but look at this in photo mode:



Screeenshot from the Debug menu only created black images.

Here is the log created from the "Don't click me!" code:

https://pastebin.com/08uQPXaZ

[a1ex]

Ouch, these pixels over the screen don't look good at all.

The bottom bar hack can be commented out from internals.h (it's not needed for the log).

The extra loggers are still there, and very verbose; comment them out.