Canon 100D / SL1

[OlRivrRat]

   The Thlot Plickens ; I reformatted that card via My Mac & placed 30Sep Build on it & went through the process

of Firmware Upgrade in Cam which seemed to go as planned. Restarted Cam as asked & Nothing, Cam Froze.

Reformatted card via Mac & put 12Jul Build on it, went through "process" & all is fine. Put 30Sep on a Diff card &

Cam won't start, Freezes with No Lights. Will run fine on 12Jul Build.

[OlRivrRat]

   All seemed well with the Sep Builds Before some exploring I did a couple of days back into

"crop_rec_4k.2017Sep27". Posted this a couple of pages back.

           Had posted this over on "crop_rec on steroids" , not sure if it has any implications here >

  Activating "mlv_lite" on My SL1 running "crop_rec_4k.2017Sep27" causes all Modules to "err" ~

Using "mlv_rec / Raw video (MLV)" seems to work fine & allows recording ~ Have not Processed yet ~

   Trying to run "crop_rec_4k.2017Sep28" makes My SL1 Very Unhappy ~

   That may very well have nothing to do with what is happening now but thought I'd put it out

there for the Wizards to Mull. Don't remember now just what All the Symptoms were but do remember

Not Liking & Not wanting to try that again.

[IDA_ML]

Thanks a lot for these important warnings, guys !  Nikfreak, please keep us informed on how things develop.

[OlRivrRat]

   Just loaded 15Sep Build on 1 of the cards that was a No Start with 30Sep on it & the Cam is running

Fine with AF in FlexZone[]. Now I'm taking a break. Hoping My poor little SL1 On/Off Switch & TrapDoor

survive all this abuse.

       -------> Please Ignore Above ? I Goofed & Reloaded 12Jul <------------

           Even with AF in FlexZone[] the Sep Builds Won't Start Cam (No Lights > Frozen on startup).

[a1ex]

Double-checking the startup process in QEMU:

Code: [Select]

[****] Starting task 44ccc4(0) init
[BOOT] expecting armlib to overwrite 107770: E28F0F69 (task id 20002)
[BOOT] autoexec.bin loaded at 44C100 - 4CE540.
...
[BOOT] changing AllocMem_end:
0x004be0a8:  e59f1158      ldr r1, [pc, #344] ; 0x4be208
[BOOT] changing AllocMem limits:
0x004be0a8:  e59f1158      ldr r1, [pc, #344] ; 0x4be208
0x004be0ac:  e241087f      sub r0, r1, #8323072 ; 0x7f0000
0x004be0a8:  e59f1158      ldr r1, [pc, #344] ; 0x4be208
0x004be0ac:  e3a0084e      mov r0, #5111808 ; 0x4e0000
K346 READY
[      init:ff0c3350 ] init_pool 4E0000 - C3C000
...
[BOOT] 107770 now contains 0, restoring E28F0F69.

without ML:

Code: [Select]

K346 READY
[      init:ff0c3350 ] init_pool 44C000 - C3C000

Looks fine to me...

[Danne]

Unrelated but about eos100D. I wonder what the progress is around raw_twk? I tried to compile it but seems it won´t work. Checking in stubs.S at it misses the stub NSTUB(0xFFAD1524 - RAM_OFFSET,  AbortEDmac):

Code: [Select]

/** EDMAC **/
NSTUB(   0x34BC0,  ConnectReadEDmac)
NSTUB(   0x34AFC,  ConnectWriteEDmac)
NSTUB(   0x351A0,  RegisterEDmacAbortCBR)
NSTUB(   0x3510C,  RegisterEDmacCompleteCBR)
NSTUB(   0x35234,  RegisterEDmacPopCBR)
NSTUB(   0x3499C,  SetEDmac)
NSTUB(   0x34D48,  StartEDmac)
NSTUB(   0x351DC,  UnregisterEDmacAbortCBR)
NSTUB(   0x35148,  UnregisterEDmacCompleteCBR)
NSTUB(   0x35270,  UnregisterEDmacPopCBR)

When I find the stubs in disassembled file I try to run with these changes which gives me a black screen:

Code: [Select]

NSTUB(0xFFAD1524 - RAM_OFFSET,  AbortEDmac)
NSTUB(0xFFAD1078 - RAM_OFFSET,  ConnectReadEDmac)
NSTUB(0xFFaD0FB4 - RAM_OFFSET,  ConnectWriteEDmac)
NSTUB(0xFFAD1658 - RAM_OFFSET,  RegisterEDmacAbortCBR)
NSTUB(0xFFAD15C4 - RAM_OFFSET,  RegisterEDmacCompleteCBR)
NSTUB(0xFFAD16EC - RAM_OFFSET,  RegisterEDmacPopCBR)
NSTUB(0xFFAA0E54 - RAM_OFFSET,  SetEDmac)
NSTUB(0xFFAA1200 - RAM_OFFSET,  StartEDmac)
NSTUB(0xFFAA1694 - RAM_OFFSET,  UnregisterEDmacAbortCBR)
NSTUB(0xFFAD1600 - RAM_OFFSET,  UnregisterEDmacCompleteCBR)
NSTUB(0xFFAD1728 - RAM_OFFSET,  UnregisterEDmacPopCBR)
Yes, I might be risking stuff here but what can be said abut raw_twk? All I got was a black screen when running mlv_lite.

[IDA_ML]

@Danne: Are there no focus pixel on output when filming lossless 2.5k?

No, there are no focus points on the video when shooting at 5x magnification or at least I never saw any.  The frame grab was taken from the dng sequence as you see it. 

[Danne]

Thanks IDA_ML.

I encountered a bug with 100D and movie crop mode with the crop_rec_4k branch. I don´t know if it´s there with 100D_merge_fw101, maybe someone can test. I´m getting ready for work. Anyway. The issue seems related to some shut down or start up routines. Steps to reproduce:
I filmed with a manual lens. Not sure if it´s because of that. It´s also not always reproducible. Right now I can´t get reproduce. Go figure.

Scenario 1
start the camera fresh and enable mlv_rec, enable movie crop mode, restart camera, start filming. Nothing gets recorded, live view border flicker a bit, you might have to do a battery pull.

Trying to fix it:
Scenario 2
Start the camera select mlv_rec and movie crop mode but shut down the camera by opening the battery door instead. Then start it by closing the battery door. Start film. Movie crop mode now should work.

*UPDATE
Ok, seems I reproduced it every time now. Seems related to the order to which you enabled RAW video(MLV) and Movie crop mode

Broken scenario
Select first RAW video(MLV) then touch shutter to enter back to live view. Now go back to ML menu and select Movie crop mode then start to film. This should break things.

Working scenario
First select Movie crop mode then select RAW video(MLV) in that order and start film. Should work now.

[dfort]

Wow--that's a great find. Verified that the same scenarios apply to the EOSM. Most likely it also works the same way on the 700D but I've got to get back to backing up the files I shot over the weekend so that will tie up my computer overnight.

[OlRivrRat]

   Just loaded 02Oct Build > No Start, No Lights, Cam Frozen. Can do Batt' remount & put in card with

12Jul & all is fine.

[brigantes]

Im so impressed with all the work you guys put in and the things you make this camera able to achieve. It amazes me that lossless mlv is working on this little camera. Im currently using raw on the 100D for some of my film pieces on my uni course.

However I've run into a problem whilst trying with the latest crop_rec_4k experimental build. I like to work in raw in Da Vinci Resolve, if I use the standard 14/12/10 bit or the 14bit lossless then everything is fine, however if is use the 12 bit / 11...8 bit lossless then I get pink, magenta colour in the highlights in the DNG files in resolve and ACR, if I under expose so there are no real highlights these aren't present.

This also shows on the display whilst previewing or recording (I also get a darkened display as mentioned in an earlier post) and if I half press the shutter display returns to normal. I've tried black/ white level settings, etc, these made no difference. The only way I could remove this colour cast in the highlights was using the reconstruct green channel option in MLV Producer, but MLV producer isn't my preferred workflow.

I'd really like to be able to use lossless and I'm just wondering if Im missing a setting somewhere on camera or in conversion software or if this is a bug. I couldn't find any info on this in any of the other topics but I could have missed something.

[canneloni]

Sep30 Nightly Build works again! Changed Focus with Jul Build to Single zone and now it boots. I had Jul12th Build installed and deleted ML files, without formatting, copied fresh Sep10th Build over to SD Card and now it works.

Edit: Pretty sure now: face detection and single focus work, multi instantly shuts the camera down and brings boot problem. Remove battery and sd card, start Camera without SD card, switch back to single focus, camera boots again. Works every time.

Edit: All logs created with latest Nightly version and stubstest: https://drive.google.com/open?id=0BwcFy_euKD1JRkFLRDRzQ0R2RVE

[nikfreak]

ya, it's definitey the focus method's "facetracking" as well as "Flexizone()" which cause headaches.
Flexizone[] is fine.

If cam once crashed with the mewer builds on facetracking there's no way back to boot up camera with any of the new builds. You have to use an older build (people take 12th July from 1st post) and switch back the AF method if they want to use a newer build again. But using the 12th July build doesn't crash at all switching and using the AF methods.

My first test now was to use malloc-boot from 650D/700D/EOSM as we have the dryos task hooks fixed this boot method works on 100D now, too. Result for the moment is that the cam still crashes when switching AF methods but it is able to just boot up again after taking out the battery. Nightlies aren't capable of this. One tiny fault reproducable already found: taking an image with this boot method will cause image review to freeze the cam. So I will leave further tests and try to use the boot method from 6D again to see what's going on.

What i ask myself is: wtd does AF method switching write into the camera to not let it boot up again. probably hard to tell but being in simple photo mode (not LV) and switching to "Flexizone()" produces these error logs. maybe a1ex can try on qemu as it doesn't need LV to replicate:

Code: [Select]

ASSERT: 0
at ./Memory/Memory.c:575, PropMgr:3a6f4
lv:0 mode:3

PropMgr stack: 18cee0 [18cf68-18bf68]
0xUNKNOWN  @ d090:18cf60
0x0003A670 @ 3a72c:18cf38
0x00008C14 @ 3a6f0:18cf18
0x000C5708 @ c5970:18cee0

Magic Lantern version : Nightly.2017Oct02.100D101
Mercurial changeset   : 3f68cd33c46d+ (crop_rec_4k) tip
Built on 2017-10-02 06:49:12 UTC by ml@ml-VirtualBox.
Free Memory  : 100K + 2764K

ASSERT: FALSE
at ./LvCommon/LvJob.c:156, Evf:1bcd4
lv:1 mode:3

Evf stack: 1bf2a8 [1bf4b8-1be8b8]
0xUNKNOWN  @ d090:1bf4b0
0xUNKNOWN  @ 3a758:1bf488
0x0003A450 @ ff0d444c:1bf470
0xUNKNOWN  @ 3a480:1bf460
0xUNKNOWN  @ f5c4c:1bf438
0xUNKNOWN  @ 3a508:1bf418
0x0001BBF8 @ 12d74:1bf308
0x00001900 @ 1bcd0:1bf2e0
0x000C5708 @ c5970:1bf2a8

Magic Lantern version : Nightly.2017Oct02.100D101
Mercurial changeset   : 3f68cd33c46d+ (crop_rec_4k) tip
Built on 2017-10-02 06:49:12 UTC by ml@ml-VirtualBox.
Free Memory  : 100K + 3044K
Todo: old boot method (like 6d) - maybe it is something ese which changed after 12th July, who knows.

[canneloni]

For me it works just removing the SD Card and start Camera with simple Canon fw. Then switch Focus back, turn camera off, insert SD card with nightly Build and turn camera back on.

[a1ex]

maybe a1ex can try on qemu as it doesn't need LV to replicate

Looking on the above call stack, but nothing rings a bell yet - can you get a startup-log (dm-spy-experiments) with the Flexizone setting enabled? This setting appears to be stored on the MPU side. I've managed to fake it ("0x06, 0x05, 0x01, 0x49, 0x03, 0x00" instead of "0x06, 0x05, 0x01, 0x49, 0x02, 0x00" in 100D.h), but there may be more messages coming from MPU with this setting.

edit: I think I've reproduced it. I'm compiling the 100D_merge_fw101 branch with these changes:

Code: [Select]

diff -r d85e97b54bd2 platform/100D.101/Makefile.platform.default
--- a/platform/100D.101/Makefile.platform.default
+++ b/platform/100D.101/Makefile.platform.default
@@ -6,7 +6,2 @@
 
-ifeq ($(ML_SRC_PROFILE),generic)
-# Load ML at the beginning of the AllocateMemory pool
-# default 0x44C000 - 0xC3C000, patched to 0x4E0000 - 0xC3C000 (592K for us).
-RESTARTSTART    = 0x44C100
-else
 # Load ML at user_mem_start (aka heap start / DRY_HEAP_START / malloc memory pool)
@@ -15,3 +10,2 @@
 RESTARTSTART    = 0xC53A0
-endif
 
diff -r d85e97b54bd2 platform/100D.101/internals.h
--- a/platform/100D.101/internals.h
+++ b/platform/100D.101/internals.h
@@ -17,3 +17,2 @@
 /** This camera loads ML into the AllocateMemory pool **/
-#define CONFIG_ALLOCATE_MEMORY_POOL
 

and got this crash log on the virtual SD card:

Code: [Select]

ASSERT: 0
at ./Memory/Memory.c:575, PropMgr:3a6f4
lv:0 mode:0

PropMgr stack: 18cee0 [18cf68-18bf68]
0xUNKNOWN  @ d090:18cf60
0x0003A670 @ 3a72c:18cf38
0x00008C14 @ 3a6f0:18cf18
0x000C5718 @ c5948:18cee0

Magic Lantern version : Nightly.2017Oct02.100D101
Mercurial changeset   : d85e97b54bd2+ (100D_merge_fw101)
Built on 2017-10-02 08:21:43 UTC by alex@thinkpad.
Free Memory  : 128K + 3088K

edit: when running with -d debugmsg, the assert is no longer there, GUI boots, ML menu works...

edit: got this stack trace:

Code: [Select]

[MPU] Sending : 06 05 01 49 03 00
[MPU] Received: 14 13 09 25 01 04 7c fe fe fe 7c 00 00 00 00 00 00 00 00 00  (unknown spell)
[  TouchMgr:ff146a28 ] register_interrupt(null, 0x34, 0xff14687c, 0x1)
[   Startup:ff30e0c4 ] task_create(EyeFi, prio=19, stack=1000, entry=ff30e058, arg=0)
[   Startup:ff0c5364 ] task_create(LEAK, prio=1d, stack=400, entry=ff0c5110, arg=0)
[  TouchMgr:ff146a28 ] register_interrupt(null, 0x34, 0xff14687c, 0x1)
[  TouchMgr:ff146a28 ] register_interrupt(null, 0x34, 0xff14687c, 0x1)
[MPU] Received: 06 05 03 19 01 00  (spell #47)
[   Startup:ff142478 ] register_interrupt(null, 0x40, 0xff141f68, 0x0)
[   Startup:ff14248c ] register_interrupt(null, 0x2, 0xff14215c, 0x0)
[   Startup:ff1424a0 ] register_interrupt(null, 0x1, 0xff142240, 0x0)
[  TouchMgr:ff146a28 ] register_interrupt(null, 0x34, 0xff14687c, 0x1)
[MPU] Received: 06 05 02 0a 01 00  (spell #48)
[MPU] Sending : 06 05 06 11 01 00
[MPU] Sending : 06 05 06 12 00 00
[MPU] Sending : 06 05 06 26 01 00
[MPU] Sending : 46 45 0a 08 ff 1f 01 04 01 03 98 10 00 50 01 01 55 28 3d 01 01 00 48 04 01 37 46 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[MPU] Sending : 08 06 01 04 00 00 00 00
Current stack: [18cf68-18bf68] sp=18cf18                                         at [PropMgr:1900:3a6f4]
0x3A6FC(457300 &"TaskClass", 3a6fc, 19980218, 19980218)                          at [PropMgr:d090:18cf60] (pc:sp)
 0x3A670(457300 &"TaskClass", 18cf50, 18cf4c, 18cf48)                            at [PropMgr:3a72c:18cf38] (pc:sp)
  0x8C14(0, 17fcb4, 0, 650b9 "TaskClass")                                        at [PropMgr:3a6f0:18cf18] (pc:sp)
[   PropMgr:0003a6f0 ] [ASSERT] 0 at ./Memory/Memory.c:575, 3a6f4
[   PropMgr:ff146a28 ] register_interrupt(null, 0x94, 0xff14687c, 0x7)
ASSERT : ./Memory/Memory.c, Task = PropMgr, Line 575

edit: 0x8C14 is FreeMemory; since it calls FreeMemory(0), that means there was some call to AllocateMemory that failed.

edit: useful debugmsg.gdb entries:

Code: [Select]

b *0x1900
assert_log

b *0x8878
commands
  silent
  print_current_location
  printf "AllocateMemory(%x)\n", $r0
  log_result
  c
end

b *0x8C14
commands
  silent
  print_current_location
  printf "FreeMemory(%x)\n", $r0
  c
end

b *0x8144
commands
  silent
  print_current_location
  printf "init_pool %X - %X\n", $r0, $r1
  c
end


[nikfreak]

Did a quick test by reversing this commit and adding the cache related parts (guitask) back to boot-hack.c. camera boots up but behaves the same:

• as long as facetracking or Flexizone() are set the camera won't boot up (lcd stay black)
• taking out card and battery then booting up camera and setting to Flexizone[] let's the cam boot up cam and ML with card again

So it doesn't appear to be the boot method (btw 70d doesn't appear to have any problems when switching AF methods and AF modes (but uses same boot method)). So the big Q is what changed in between my 12th July build and latest builds. Guess to find out we would have to compile commit by commit to see when it breaks.

Will check my dmspy branches to get the log.

[nikfreak]

FYI: compiled from

Code: [Select]

Revision: 15755
Changeset: 02965e52b50808b7d85568903a6f92ae64b71b9d [02965e52b508]
Parents: 15751
Author: alex@thinkpad
Date: Montag, 24. Juli 2017 13:00:07
Branch: 100D_merge_fw101
Labels:
100D: enabled CONFIG_EDMAC_RAW_SLURP
and everything appears to be fine. No crash. Nothing. Switching Af methods works. cam runs fine and boots up again whatever af method is set. Now going to check

Code: [Select]

Revision: 15759
Changeset: 4f97f4f6c8971f1154d235dd52bfe878ec8e4da9 [4f97f4f6c897]
Parents: 15758
Author: alex@thinkpad
Date: Montag, 24. Juli 2017 13:53:35
Branch: 100D_merge_fw101
Labels:
100D: fix task_dispatch_hook
and see what happens.

Update1: 4f97f4f6c897 is ok. No problems with it. Continuing...

Update2: 9f943d913581 has the crash / errors inbuilt

Update3: 1cfca215e705 has the crash / errors inbuilt, too

Update4: 2029c4408382 has the crash / errors inbuilt, too

Update5: What's left: 67684107fac1 which is used somewhere in boot-hack.c. Continuing....

[a1ex]

QEMU:
4f97f4f6c897: clean
02965e52b508: clean
9f943d913581: crash log
1cfca215e705: crash log
2029c4408382: crash log
67684107fac1 (CONFIG_TSKMON): crash log...
67684107fac1 with tskmon_task_dispatch(next_task) commented out: OK!
with only null pointer check enabled: no GUI, no crash log...

[nikfreak]

Yap, it's definitely 67684107fac1 which is crashing, too. But as soon as undefining CONFIG_TSKMON everything is ok again. Just going to compile from latest commit and undefine CONFG_TSKMON again to 1000% approve it.

[nikfreak]

Yes, approved. Compiled from latest commit and disabled CONFIG_TSKMON: everything OK. No errors / crashes.

[a1ex]

Null pointer bug in Canon code:

Code: [Select]

./run_canon_fw.sh 100D,firmware=boot=0 -d callstack -s -S
...

CTRL-C
(gdb) watch *0
Hardware watchpoint 4: *0
(gdb) c

...

Hardware watchpoint 4: *0

Old value = 0xe1a00000
New value = 0x80c3e100
0x00020a94 in ?? ()
(gdb) print_callstack
Current stack: [1be8b0-1bdcb0] sp=1be668                                         at [Gmt:20a94:20a2c]
0x3A6FC(626578 &"TaskClass", 3a6fc, 19980218, 19980218)                          at [Gmt:d090:1be8a8] (pc:sp)
 0xFF0D4F18(6256d0, 13, 955bdc, 0)                                               at [Gmt:3a758:1be880] (pc:sp)
  0x3A450(62659c &"StateObject", 6256d0, 13, 955bdc)                             at [Gmt:ff0d4f70:1be848] (pc:sp)
   0x3A488(62659c &"StateObject", 6256d0, 13, 955bdc)                            at [Gmt:3a480:1be838] (pc:sp)
    0xFF174094(6256d0, 955bdc, 0, ff174094)                                      at [Gmt:3a508:1be818] (pc:sp)
     0xFF17D3C8(6256d0, 3, 8004001d, ffff0046)                                   at [Gmt:ff175e7c:1be748] (pc:sp)
      0xFF17D334(6256d0, 6265f4 &"StateObject", 16, 0)                           at [Gmt:ff17d454:1be738] (pc:sp)
       0x3A450(6265f4 &"StateObject", 6256d0, 16, 0)                             at [Gmt:ff17d368:1be710] (pc:sp)
        0x3A488(6265f4 &"StateObject", 6256d0, 16, 0)                            at [Gmt:3a480:1be700] (pc:sp)
         0xFF189ADC(6256d0, 0, 0, ff189adc)                                      at [Gmt:3a508:1be6e0] (pc:sp)
          0xFF180F58(6256d0, 0, 0, a7c)                                          at [Gmt:ff189bcc:1be6d0] (pc:sp)
           0x20BE4(0, 625e48, 10000, 1)                                          at [Gmt:ff180f8c:1be6c0] (pc:sp)
            0x20A0C(1, 0, 1, 1)                                                  at [Gmt:20d6c:1be688] (pc:sp)

And bug on our side when reporting this kind of errors (likely we are doing something incompatible with new-style DryOS task hooks).

The watchpoint does not trigger with default AF setting (vanilla MPU spells).

Thanks nikfreak & testers for narrowing down

[nikfreak]

lol, no, thank you, really! Also props to the testers for pointing us to the right direction.

[a1ex]

Okay, for some reason, figuring out the task name (when calling is_taskid_valid) causes trouble. That function works and gives the correct task name eventually, but that happens after a couple of context switches (around 100 in my simulation).

Normally, our null pointer checker undoes any value written at 0, as soon as it detects a change (that is, when DryOS switches to some other task, calling our hook in the process). If we undo that memory write, Canon code depending on that value probably gets screwed up. If we don't undo it, the null pointer check gets called again, from those context switches from is_taskid_valid, and eventually this ends up overflowing the stack.

Time to understand how to walk the DryOS task structure?

( no, found an easier way )

P.S. @nikfreak - meanwhile, can you trigger a null pointer bug on the 70D? e.g. MEM(0) = 1234 in don't click me.

[nikfreak]

Done. 70D let's LCD get black once "Don't click me" 'd. Taking a picture seems to work, restarting, too but the LCD stays always black. need to take battery out to get LCD working again.

[nikfreak]

and the crash log for 70D as already experienced on 100D:

Code: [Select]

ASSERT: 0
at ./Memory/Memory.c:575, PropMgr:3db28
lv:1 mode:3

PropMgr stack: 170ee0 [170f68-16ff68]
0xUNKNOWN  @ ef80:170f60
0x0003DAA4 @ 3db60:170f38
0x0000AAF8 @ 3db24:170f18
0x0044C468 @ 44c4ec:170ee0

Magic Lantern version : Nightly.2017Oct02.70D112
Mercurial changeset   : 32ccab6c6292+ (70D_merge_fw112) tip
Built on 2017-10-02 11:06:54 UTC by ml@ml-VirtualBox.
Free Memory  : 229K + 2500K