How to run Magic Lantern into QEMU?!...

Started by jplxpto, September 23, 2012, 08:29:02 PM

Previous topic - Next topic

0 Members and 1 Guest are viewing this topic.

reddeercity

Ok here the menu.Log & menu.txt just incase there a problem reading the .Log file plus here are menu screen shots that qemu made Menu_Screen_shots.rar there are some black image ,
can only assume that those are from thing that are not functional in qemu.

a1ex

The test suite doesn't exactly work out of the box; there are a few patches to vncdotool that I've installed manually on the build server. Need to handle these in the installer script.

For FRSP, looks like "make clean install_qemu" no longer works in one command, figure out why. Workaround: split the command into "make clean" and "make install_qemu".

In any case, FA_CaptureTestImage emulation doesn't work on 5D2 yet. It does work on 50D, 60D and other DIGIC 4 models though. The test suite only covers the following models:

Testing FA_CaptureTestImage...
    5D3: OK (no display)
   500D: OK
   550D: OK
    50D: OK
    60D: OK
  1100D: OK (no display)
  1200D: OK

reddeercity

Ok , I'll keep working at it . Thanks

reddeercity

Almost got ML to run in qemu , use this command  make -C ../magic-lantern/platform/5D2.212 install_qemu
./run_canon_fw.sh 5D2,firmware="boot=1" -s -S & arm-none-eabi-gdb -x 5D2/patches.gdb



I cann't get in to the ml menu , is there a "trash can" key ?
tried "M" key nothing

So when i tried to shut qemu while ml was loaded i got a interesting result


Just kept looping until i closed terminal window , couldn't find any recording , never seen this before .

Edit: Found the recording , in the cf.img , just chick it to open it up and ML is installed in there plus a MVI_8611.MOV was saved but with "0" data
in the setting folder I found the magic.cfg file
# Magic Lantern Nightly.2018Jul22.5D2212 (cc1331663f9c+ (qemu))
# Built on 2018-07-23 04:42:22 UTC by dmiazga@reddeercity
# Configuration saved on 2017/09/30 12:15:00
disp.mode.x = 215


Hope I can get this to work right to test builds

reddeercity

Seem Intel cpu has a better time emulating ml in qemu  , the above screen shots are from my AMD desktop .
This one below is from my Intel i5 laptop



Edit: I can get a .MOV/h264 to start by pressing the space but can't stop it nor can I bring up the ml menu so I can't load any
modules , the only way to stop the recording it to power down then goes to the blue disc "recording ..." then I have to crash it to make it stop .

reddeercity

Back to the cr2 frsp test
make -C ../magic-lantern/minimal/qemu-frsp MODEL=5D2 CONFIG_QEMU=y clean install_qemu
env QEMU_EOS_VRAM_PH_QR_RAW='/path/to/IMG_1234.CR2' ./run_canon_fw.sh 5D2,firmware="boot=1"


dosen't work as noted before , it gets 2 errors
make -C ../magic-lantern/minimal/qemu-frsp MODEL=5D2 CONFIG_QEMU=y  install_qemu
make: Entering directory '/home/david/magic-lantern/minimal/qemu-frsp'
Using /usr/bin/arm-none-eabi-gcc (from PATH).
../../Makefile.inc:70: removing ../../platform/*/magiclantern.sym
[ RM dir   ]   /home/david/magic-lantern/minimal/qemu-frsp/zip/
[ RM       ]   ../../platform/*/magiclantern.sym
mkdir -p /home/david/magic-lantern/minimal/qemu-frsp/zip
make -C ../../installer/5D2.212 build_fir
make[1]: Entering directory '/home/david/magic-lantern/installer/5D2.212'
[ VERSION  ]   ../../platform/5D2.212/version.bin
[ VERSION  ]   ../../platform/5D2.212/version.c
[ CC       ]   version.o
[ LD       ]   magiclantern
[ OBJCOPY  ]   magiclantern.bin
[ STAT     ]   magiclantern.bin
magiclantern.bin: 30424 bytes
[ CC       ]   reboot.o
[ LD       ]   autoexec-fir
[ OBJCOPY  ]   autoexec-fir.bin
[ XOR_CHK  ]   autoexec-fir.bin
python ../../../dumper/build_fir.py -r ../../../dumper/5D200212.FIR autoexec-fir.bin ML-SETUP.FIR 0x80000218
python: can't open file '../../../dumper/build_fir.py': [Errno 2] No such file or directory
../../platform/Makefile.platform.extras:5: recipe for target 'build_fir' failed
make[1]: [build_fir] Error 2 (ignored)
make[1]: Leaving directory '/home/david/magic-lantern/installer/5D2.212'
cp ../../installer/5D2.212/ML-SETUP.FIR ML-SETUP.FIR
cp: cannot stat '../../installer/5D2.212/ML-SETUP.FIR': No such file or directory
../../platform/Makefile.platform.extras:46: recipe for target 'ML-SETUP.FIR' failed
make: *** [ML-SETUP.FIR] Error 1
make: Leaving directory '/home/david/magic-lantern/minimal/qemu-frsp'


it seem to crash on "ML-SETUP.FIR"
Any hints/helps  :D

If i run
- compile from minimal/qemu-frsp with "make MODEL=5D2

i get it to compile, with whole branch of file  plus a Autoexec
david@reddeercity:~/magic-lantern/minimal/qemu-frsp$ MODEL=5D2 make
Using /usr/bin/arm-none-eabi-gcc (from PATH).
[ VERSION  ]   ../../platform/5D2.212/version.bin
[ CPP      ]   magiclantern.lds
[ AS       ]   entry.o
[ CC       ]   minimal.o
[ CC       ]   font_direct.o
[ CC       ]   raw.o
[ CC       ]   vram.o
[ CC       ]   propvalues.o
[ CC       ]   stdio.o
[ CC       ]   imgconv.o
[ CC       ]   dialog_test.o
[ AR       ]   strrchr.o
[ AR       ]   dietlibc.a
[ AR       ]   lib_a-setjmp.o
[ AR       ]   newlib-libc.a
[ CP       ]   newlib-libm.a
[ CP       ]   gcc-libgcc.a
[ LD       ]   magiclantern
[ OBJCOPY  ]   magiclantern.bin
[ STAT     ]   magiclantern.bin
magiclantern.bin: 35653 bytes
[ CC       ]   reboot.o
[ CC       ]   disp_direct.o
[ CC       ]   footer.o
[ LD       ]   autoexec
[ OBJCOPY  ]   autoexec.bin
[ XOR_CHK  ]   autoexec.bin

Program Headers:
  Type           Offset   VirtAddr   PhysAddr   FileSiz MemSiz  Flg Align
  LOAD           0x000060 0x0004e000 0x0004e000 0x08b45 0x0e524 RWE 0x10

but not sure what to do with it , Can i call that minimal build up in qemu ?
with out making the cf.img , plus how do load a nightly build in qemu
i'm kind of lost on the proper syntax . :)

Edit : I almost forgot i had to add a folder in  Home~/magic-lantern/minimal/5D2/Makefile
MODEL=5D2
include ../Makefile.minimal

there was no 5d2 make file so i add it ,

a1ex

Unable to reproduce your error. Here it doesn't try to build any FIR files from the minimal target. edit: reproduced, here's a workaround:


touch ../magic-lantern/installer/5D2.212/ML-SETUP.FIR
make -C ../magic-lantern/minimal/qemu-frsp MODEL=5D2 clean
make -C ../magic-lantern/minimal/qemu-frsp MODEL=5D2 CONFIG_QEMU=y install_qemu


I also didn't have to create any directories; looking into it.

Once you get it to compile, run the emulation with -d debugmsg,io:

./run_canon_fw.sh 5D2,firmware=boot=1 -d debugmsg,io


and it will lock up here:

[GPIO] at ShootCapt:FF9B72E4:FFA360E0 [0xC022001C] -> 0x1       : GPIO_7


The cleanest way to get further is to get a MMIO log during photo capture, that includes this register, to see what values the firmware expects from there. You can do that from either dm-spy-experiments or io_trace_full, with CONFIG_DEBUG_INTERCEPT=y and CONFIG_MMIO_TRACE=y. In io_trace.c, use this definition:

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


and... pray it won't lock up...

If it locks up, there's the "old-school" way of adding manual logging hooks in dm-spy-extra.c. Run the emulation with -d io_log and you'll get this line:

    { 0xFF9B72E8, "0xC022001C", R(0), mmio_log },     /* [GPIO] GPIO_7 at ShootCapt:FF9B72E4 (0x1)*/


Set CONFIG_MMIO_TRACE=n in Makefile.user, copy that line into dm-spy-extra.c under CONFIG_5D2 and this time it should not lock up. However, this method only works with a small number of logging hooks at a time, while io_trace attempts to capture everything at once. Still couldn't figure out why it locks up on DIGIC 4.

reddeercity

Thanks @a1ex for the help ! I'll give these workaround a try this weekend .  :)

a1ex

Nice, also committed a fix, so the workaround should no longer be needed. Also, "make clean install_qemu" appears to work with -j1, but couldn't figure out how to specify the correct dependencies so it also works with -j8. Help welcome.

Currently working on emulating FA_CaptureTestImage on most other models. Current status (not yet committed):
- 5D2 almost working (showing Image Power Failure in logs; changing that register breaks other models)
- 6D almost working (need a reference test image, CR2 saves a smaller area than what is captured)
- 70D working
- 1100D almost working (unsure how the preview looks like)
- 600D working (the ROM I've got had Auto ISO by default, had to change it from the test code)
- 650D, 700D, 100D all failing in the same spot, didn't figure out yet first two working
- 1300D, EOSM, 1300D all failing early, didn't check yet
- VxWorks models not compiling the minimal example, didn't check yet
- DIGIC 6/7: image capture tasks not started, will leave these for later

reddeercity

Got busy on the weekend , just got around to trying this out again .
Thanks @a1ex for the workaround , I see there a commit to fix the issue but i just when with the work around .
Compiled Ok , then ran
./run_canon_fw.sh 5D2,firmware=boot=1 -d debugmsg,io
and as noted it locks up at
[GPIO] at ShootCapt:FF9B72E4:FFA360E0 [0xC022001C] -> 0x1       : GPIO_7
I tried to get same info before it locks up , I crashed qemu to get the terminal log
not too much there at least to me , (I'll post the log/text file shortly) there was some hopeful info when i ran the FA_CaptureTestImage , qemu first had a gray screen  (that's normal i guess) then it turn black and said "No Image" and stayed black and no key strokes could bring up the canon menu gui .
When i switch to serial0 i see this

Interesting thing , when i dropped the
-d debugmsg,io
It didn't lockup in  terminal
./run_canon_fw.sh 5D2,firmware=boot=1
DebugMsg=0xFF86AF64 (from GDB script)
Gtk-Message: 20:56:04.553: Failed to load module "canberra-gtk-module"
Lockdown read 1
Lockdown read 1
Lockdown read 0
Lockdown read 0
Lockdown read 2
Lockdown read 2
Lockdown read 3
Lockdown read 3
Lockdown read 4
Lockdown read 4
Lockdown read 5
Lockdown read 5
00000000 - 00000FFF: eos.tcm_code
40000000 - 40000FFF: eos.tcm_data
00001000 - 1FFFFFFF: eos.ram
40001000 - 5FFFFFFF: eos.ram_uncached
E8000000 - E8052FFF: eos.ram_extra
F0000000 - F0FFFFFF: eos.rom0
F1000000 - F1FFFFFF: eos.rom0_mirror
F2000000 - F2FFFFFF: eos.rom0_mirror
F3000000 - F3FFFFFF: eos.rom0_mirror
F4000000 - F4FFFFFF: eos.rom0_mirror
F5000000 - F5FFFFFF: eos.rom0_mirror
F6000000 - F6FFFFFF: eos.rom0_mirror
F7000000 - F7FFFFFF: eos.rom0_mirror
F8000000 - F8FFFFFF: eos.rom1
F9000000 - F9FFFFFF: eos.rom1_mirror
FA000000 - FAFFFFFF: eos.rom1_mirror
FB000000 - FBFFFFFF: eos.rom1_mirror
FC000000 - FCFFFFFF: eos.rom1_mirror
FD000000 - FDFFFFFF: eos.rom1_mirror
FE000000 - FEFFFFFF: eos.rom1_mirror
FF000000 - FFFFFFFF: eos.rom1_mirror
C0000000 - CFFFFFFF: eos.mmio
[EOS] loading './5D2/ROM0.BIN' to 0xF0000000-0xF0FFFFFF
[EOS] mirrored data; unique 0x400000 bytes repeated 0x4 times
[EOS] loading './5D2/ROM1.BIN' to 0xF8000000-0xF8FFFFFF
[EOS] mirrored data; unique 0x800000 bytes repeated 0x2 times
[MPU] warning: non-empty spell #5 (PROP_CARD3_STATUS) has duplicate(s): #16
[MPU] warning: non-empty spell #17 (PROP_CARD1_STATUS) has duplicate(s): #48
[MPU] warning: non-empty spell #31 (PROP 8003001A) has duplicate(s): #36
[MPU] warning: non-empty spell #37 (PROP_VIDEO_MODE) has duplicate(s): #38

[MPU] Available keys:
- Arrow keys   : Navigation
- Numpad keys  : Joystick (8 directions)
- Numpad 5     : Joystick center
- PgUp, PgDn   : Sub dial (rear scrollwheel)
- [ and ]      : Main dial (top scrollwheel)
- SPACE        : SET
- DELETE       : guess (press only)
- M            : MENU (press only)
- P            : PLAY (press only)
- I            : INFO/DISP (press only)
- L            : LiveView (press only)
- W            : Pic.Style (press only)
- Z/X          : Zoom in/out
- Shift        : Half-shutter
- 0/9          : Mode dial (press only)
- V            : Movie mode (press only)
- B            : Open battery door
- C            : Open card door
- F10          : Power down switch
- F1           : show this help

Setting BOOTDISK flag to FFFFFFFF
[DMA3] Copy [0xF8760000] -> [0xE8000000], length [0x00053000], flags [0x00000001]
[DMA3] OK
FFFF2368: MCR p15,0,Rd,cr6,cr0,0:  946_PRBS0 <- 0x3F       (00000000 - FFFFFFFF, 0x100000000)
FFFF2370: MCR p15,0,Rd,cr6,cr1,0:  946_PRBS1 <- 0x3D       (00000000 - 7FFFFFFF, 0x80000000)
FFFF2378: MCR p15,0,Rd,cr6,cr2,0:  946_PRBS2 <- 0xE0000039 (E0000000 - FFFFFFFF, 0x20000000)
FFFF2380: MCR p15,0,Rd,cr6,cr3,0:  946_PRBS3 <- 0xC0000039 (C0000000 - DFFFFFFF, 0x20000000)
FFFF2388: MCR p15,0,Rd,cr6,cr4,0:  946_PRBS4 <- 0xFF80002D (FF800000 - FFFFFFFF, 0x800000)
FFFF2390: MCR p15,0,Rd,cr6,cr5,0:  946_PRBS5 <- 0x39       (00000000 - 1FFFFFFF, 0x20000000)
FFFF2398: MCR p15,0,Rd,cr6,cr6,0:  946_PRBS6 <- 0xF780002D (F7800000 - F7FFFFFF, 0x800000)
FFFF23A0: MCR p15,0,Rd,cr2,cr0,0: DCACHE_CFG <- 0x70       
FFFF23A8: MCR p15,0,Rd,cr3,cr0,0:       DACR <- 0x70       
FFFF23AC: MCR p15,0,Rd,cr2,cr0,1: ICACHE_CFG <- 0x70       
FFFF23B0: MCR p15,0,Rd,cr5,cr0,0:    DATA_AP <- 0x3FFF     
FFFF23B8: MCR p15,0,Rd,cr5,cr0,1:    INSN_AP <- 0x3FFF     
FFFF23BC: MRC p15,0,Rd,cr1,cr0,0:      SCTLR -> 0x2078
FFFF23BC: MCR p15,0,Rd,cr1,cr0,0:      SCTLR <- 0xC000307D
FFFF05F8: MCR p15,0,Rd,cr9,cr1,1: XSCALE_UNLOCK_ICACHE <- 0x6        (00000000 - 00000FFF, 0x1000)
FFFF05F8: MRC p15,0,Rd,cr1,cr0,0:      SCTLR -> 0xC000307D
FFFF05F8: MCR p15,0,Rd,cr1,cr0,0:      SCTLR <- 0xC004307D
FFFF0634: MRC p15,0,Rd,cr1,cr0,0:      SCTLR -> 0xC004307D
FFFF0634: MCR p15,0,Rd,cr1,cr0,0:      SCTLR <- 0xC004107D
FFFF0634: MCR p15,0,Rd,cr9,cr1,0: XSCALE_LOCK_ICACHE_LINE <- 0x40000006 (40000000 - 40000FFF, 0x1000)
FFFF0634: MRC p15,0,Rd,cr1,cr0,0:      SCTLR -> 0xC004107D
FFFF0634: MCR p15,0,Rd,cr1,cr0,0:      SCTLR <- 0xC005107D
CF LOAD OK.
Open file for read : AUTOEXEC.BIN
Total_size=A3A0
Now jump to AUTOEXEC.BIN!!
0010C08C: MRC p15,0,Rd,cr1,cr0,0:      SCTLR -> 0xC005107D
0010C08C: MCR p15,0,Rd,cr1,cr0,0:      SCTLR <- 0xC005107D
0010BF60: MCR p15,0,Rd,cr7,cr5,0: FlushICache <- 0x0       
00809820: MCR p15, ...          : CACHEMAINT x770 (omitted)
00809820: MCR p15,0,Rd,cr7,cr5,0: FlushICache <- 0x0       
[boot] copy_and_restart 0x4e000 (319488)
0004E134: MCR p15, ...          : CACHEMAINT x257 (omitted)
0004E134: MCR p15,0,Rd,cr7,cr5,0: FlushICache <- 0x0       
K218 READY
[DMA1] Copy [0xF85B0000] -> [0x40302E00], length [0x001AD038], flags [0x00030001]
[DMA1] OK
[DMA2] Copy [0xF0330000] -> [0x404B2F00], length [0x0002F5AC], flags [0x00030001]
[DMA2] OK
     0:    26.112 [STARTUP] ICU Firmware Version 2.1.2 ( 6.9.8 )
[DMA2] Copy [0xF032E000] -> [0x404F3100], length [0x00000994], flags [0x00030001]
[DMA2] OK
[DMA2] Copy [0xF0390000] -> [0x404F4300], length [0x00018028], flags [0x00030001]
[DMA2] OK
[DMA2] Copy [0xF800E000] -> [0x40514500], length [0x000007E0], flags [0x00030001]
[DMA2] OK
[MPU] Received: 06 04 02 00 00 00  (Init - spell #1)
[MPU] Sending : 08 07 01 33 03 03 03 00  (PROP 80000029)
[MPU] Sending : 06 05 01 20 01 00  (PROP_CARD1_EXISTS)
[MPU] Sending : 06 05 01 21 00 00  (PROP_CARD2_EXISTS)
[MPU] Sending : 06 05 01 22 00 00  (PROP_CARD3_EXISTS)
[MPU] Sending : 06 05 03 0c 01 00  (PROP_CARD1_RECORD)
[MPU] Sending : 06 05 03 0d 01 00  (PROP_CARD2_RECORD)
[MPU] Sending : 06 05 03 0e 01 00  (PROP_CARD3_RECORD)
[MPU] Sending : 08 06 01 23 00 00 00 00  (PROP_CARD1_STATUS)
[MPU] Sending : 08 06 01 24 00 00 00 00  (PROP_CARD2_STATUS)
[MPU] Sending : 08 06 01 25 00 00 00 00  (PROP_CARD3_STATUS)
[MPU] Sending : 06 05 01 2e 01 00  (PROP_SAVE_MODE)
[MPU] Sending : 06 05 01 2c 01 00  (PROP_CURRENT_MEDIA)
[MPU] Sending : 06 05 03 20 01 00  (PROP_STARTUP_CONDITION)
[MPU] Sending : 06 05 01 3d 00 00  (PROP_TEMP_STATUS)
[MPU] Sending : 06 05 01 42 00 00  (PROP_PHOTO_STUDIO_MODE)
[MPU] Sending : 06 05 01 43 00 00  (PROP 80040017)
[MPU] Sending : 06 05 01 46 00 00  (PROP_PHOTO_STUDIO_ENABLE_ISOCOMP)
[MPU] Sending : 06 05 01 44 00 00  (PROP 80040018)
[MPU] Sending : 06 05 01 00 03 00  (PROP_SHOOTING_MODE)
[MPU] Sending : 2c 2a 02 00 03 03 05 00 00 00 00 48 00 00 09 17 70 00 00 fe 00 85 07 08 01 03 06 00 00 04 07 08 01 03 01 00 00 07 08 00 73 3b 01 00  (Init group)
[MPU] Sending : 06 05 01 37 00 00  (PROP_CARD_EXTENSION)
[MPU] Sending : 06 05 01 49 00 00  (PROP_LIVE_VIEW_AF_SYSTEM)
[MPU] Received: 08 06 00 00 02 00 00 00  (Complete WaitID = 0x80000001 Init - spell #2)
[MPU] Sending : 06 05 01 3e 00 00  (PROP_ELECTRIC_SHUTTER_MODE)
[MPU] Sending : 08 06 01 45 00 10 00 00  (PROP_METERING_TIMER_FOR_LV)
[MPU] Sending : 06 05 01 48 02 00  (PROP_LIVE_VIEW_MOVIE_SELECT)
[MPU] Sending : 06 05 01 4b 02 00  (PROP_LIVE_VIEW_VIEWTYPE_SELECT)
[MPU] Sending : 06 05 01 40 00 00  (PROP_STROBO_ETTLMETER)
[MPU] Sending : 06 05 01 41 00 00  (PROP_STROBO_CURTAIN)
[MPU] Sending : 06 05 01 3f 00 00  (PROP_FLASH_ENABLE)
[MPU] Sending : 16 14 01 4e 00 00 00 00 00 00 00 00 00 00 00 1e 00 00 00 0f 00 00  (PROP_VIDEO_MODE)
[MPU] Sending : 0e 0c 02 05 08 00 00 01 00 00 00 00 00 00  (PROP_CFN_1)
[MPU] Sending : 0c 0a 02 06 06 00 03 00 03 00 00 00  (PROP_CFN_2)
[MPU] Sending : 14 13 02 07 09 00 00 00 01 00 00 00 02 06 08 00 00 02 00 00  (PROP_CFN_3)
[MPU] Sending : 0e 0c 02 08 08 00 00 00 00 02 00 00 00 00  (PROP_CFN_4)
[MPU] Sending : 0a 08 03 2f 00 00 00 00 00 00  (PROP_SPECIAL_OPTION)
[MPU] Sending : 06 05 03 05 02 00  (PROP_POWER_LEVEL)
[MPU] Sending : 1e 1c 03 30 53 65 53 65 65 65 65 65 00 a0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  (PROP 8003002A)
[MPU] Sending : 0e 0c 03 2e 00 00 7c 46 00 00 7e 44 00 00  (PROP_SHUTTER_COUNTER)
[MPU] Sending : 06 05 03 35 01 00  (PROP_BATTERY_REPORT_COUNTER)
[MPU] Sending : 1c 1b 03 1d 4f 03 00 00 00 18 00 4c 50 2d 45 36 00 00 00 00 00 01 00 7e 5b 1c 57 00  (PROP_BATTERY_REPORT)
[MPU] Sending : 06 04 03 36 00 00  (PROP_BATTERY_REPORT_FINISHED)
[MPU] Sending : 06 05 01 04 00 00  (PROP_AF_MODE)
[MPU] Sending : 06 05 01 06 3b 00  (PROP_APERTURE)
[MPU] Received: 06 05 03 0e 00 00  (PROP_CARD3_RECORD - spell #3)
[MPU] Received: 06 05 01 22 00 00  (PROP_CARD3_EXISTS - spell #4)
[MPU] Sending : 14 13 02 07 09 00 00 00 01 00 00 00 02 06 08 00 00 02 00 00  (PROP_CFN_3)
[MPU] Received: 08 06 01 25 00 00 00 00  (PROP_CARD3_STATUS - spell #5)
[MPU] Received: 06 05 01 37 00 00  (PROP_CARD_EXTENSION - spell #6)
[MPU] Sending : 06 05 03 23 08 00  (unnamed)
[MPU] Sending : 0e 0c 03 24 31 39 2d 33 35 6d 6d 00 00 00  (PROP_LENS_NAME)
[MPU] Received: 0a 08 03 06 00 00 00 00 00 00  (PROP_AVAIL_SHOT - spell #10)
[MPU] Sending : 06 04 03 25 00 00  (unnamed)
[MPU] Received: 06 04 03 10 00 00  (PROP 80030008 - spell #11)
[MPU] Sending : 06 05 01 04 00 00  (PROP_AF_MODE)
[MPU] Received: 06 05 03 07 ff 00  (PROP_BURST_COUNT - spell #12)
[MPU] Sending : 06 05 03 0e 00 00  (PROP_CARD3_RECORD)
[MPU] Sending : 06 05 01 22 00 00  (PROP_CARD3_EXISTS)
[MPU] Sending : 08 06 01 25 00 00 00 00  (PROP_CARD3_STATUS)
[MPU] Sending : 06 05 01 37 00 00  (PROP_CARD_EXTENSION)
[MPU] Sending : 0a 08 01 34 08 01 07 03 01 00  (PROP_CARD1_IMAGE_QUALITY)
[MPU] Received: 06 05 01 2e 01 00  (PROP_SAVE_MODE - spell #13)
[MPU] Sending : 06 05 01 2e 01 00  (PROP_SAVE_MODE)
[MPU] Received: 0a 08 03 0b 00 00 00 00 00 00  (PROP 80030007 - spell #14)
[MPU] Received: 08 06 00 00 01 34 00 00  (Complete WaitID = 0x8000002F PROP_CARD1_IMAGE_QUALITY - spell #7)
[MPU] Sending : 0a 08 01 35 00 00 06 04 01 00  (PROP_CARD2_IMAGE_QUALITY)
[MPU] Received: 08 06 00 00 01 35 00 00  (Complete WaitID = 0x80000030 PROP_CARD2_IMAGE_QUALITY - spell #8)
[MPU] Sending : 0a 08 01 36 08 01 07 03 01 00  (PROP_CARD3_IMAGE_QUALITY)
[MPU] Received: 08 06 00 00 01 36 00 00  (Complete WaitID = 0x80000031 PROP_CARD3_IMAGE_QUALITY - spell #9)
[MPU] Received: 06 05 04 0e 00 00  (PROP 8002000D - spell #15)
[MPU] Received: 08 06 01 25 00 00 00 00  (PROP_CARD3_STATUS - spell #16)
[MPU] Sending : 08 06 01 25 00 00 00 00  (PROP_CARD3_STATUS)
    28:    33.024 [STARTUP] Ceres Disappeared
   113:    51.968 [ENG] [ENGIO](Addr:0x5c640000, Data:0x   30000)
   137:    55.040 [FM] FM_RegisterSpaceNotifyCallback
   140:    55.296 [FM] FM_RegisterNumberNotifyCallback
   176:    58.624 [MC] PROP_GUI_STATE 0
   181:    58.880 [MC] JobState 0
   182:    58.880 [MC] HDMIConnect ---> (0)
   186:    59.648 [MC] regist master CardCover
   202:   183.040 [CF] ERROR GetRotatingDeviceInfo
   203:   183.040 [CF] ERROR GetMakerAndVersionTuple : SearchTuple (CISTPL_VERS_1)
   204:   183.040 [CF] ERROR GetFirstTuple: CISTPL_CONFIG
   205:   183.040 [CF] ERROR GetConfigurationTuple
[MPU] Received: 08 06 01 23 00 01 00 00  (PROP_CARD1_STATUS - spell #17)
[MPU] Sending : 08 06 01 23 00 01 00 00  (PROP_CARD1_STATUS)
[MPU] Received: 08 06 01 26 00 64 00 00  (PROP_CARD1_FOLDER_NUMBER - spell #18)
[MPU] Received: 08 07 01 29 21 a2 00 00  (PROP_CARD1_FILE_NUMBER - spell #21)
[MPU] Received: 06 05 03 07 08 00  (PROP_BURST_COUNT - spell #19)
[MPU] Received: 0a 08 03 06 00 00 00 0c 00 00  (unknown - PROP_AVAIL_SHOT)
[MPU] Received: 06 05 03 11 01 00  (PROP_ICU_AUTO_POWEROFF - spell #22)
[MPU] Received: 06 05 02 0a 00 00  (PROP_PERMIT_ICU_EVENT - spell #23)
[MPU] Sending : 06 05 01 2c 01 00  (PROP_CURRENT_MEDIA)
[MPU] Sending : 0a 08 03 00 a1 00 00 00 00 00  (PROP 80030000)
[MPU] Received: 06 05 03 19 01 00  (PROP_TFT_STATUS - spell #24)
   247:   263.168 [SND] Seq LPC fin
[MPU] Sending : 06 05 03 04 00 00  (PROP_POWER_KIND)
   280:   270.848 [PRP] M:A1 F:0 L:0 P:0
[MPU] Sending : 14 12 03 15 01 26 4f 00 a0 00 13 00 23 91 00 00 00 00 00 00  (PROP_LENS)
[MPU] Sending : 06 05 03 17 92 00  (PROP_EFIC_TEMP)
[MPU] Sending : 08 06 01 0a 00 01 00 00  (PROP_AFPOINT)
[MPU] Sending : 06 05 01 38 00 00  (PROP 80040005)
[MPU] Sending : 06 05 01 39 00 00  (PROP 80040006)
[MPU] Sending : 06 05 01 0f 00 00  (PROP 8000000F)
[MPU] Sending : 06 05 03 23 08 00  (unnamed)
[MPU] Sending : 0e 0c 03 24 31 39 2d 33 35 6d 6d 00 00 00  (PROP_LENS_NAME)
[MPU] Sending : 06 04 03 25 00 00  (unnamed)
[MPU] Sending : 06 05 01 3d 00 00  (PROP_TEMP_STATUS)
[MPU] Sending : 14 12 03 15 01 26 4f 00 a0 00 13 00 23 91 00 00 00 00 00 00  (PROP_LENS)
[MPU] Received: 06 05 09 11 01 00  (PROP_LV_DISPSIZE - spell #25)
[MPU] Received: 12 11 09 15 00 00 00 00 00 00 00 00 00 00 00 00 00 00  (PROP 80050020 - spell #26)
[MPU] Received: 26 24 09 17 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  (PROP_LV_FOCUS_DATA - spell #27)
[MPU] Received: 08 06 03 18 00 00 00 00  (PROP 8003000F - spell #28)
[MPU] Received: 08 06 03 1f 00 00 00 00  (PROP 80030019 - spell #29)
[MPU] Received: 06 05 03 13 00 00  (PROP_LOGICAL_CONNECT - spell #30)
[MPU] Received: 06 05 03 1e 00 00  (PROP 8003001A - spell #31)
[MPU] Sending : 06 05 03 35 01 00  (PROP_BATTERY_REPORT_COUNTER)
[MPU] Sending : 1c 1b 03 1d 4f 03 00 00 00 18 00 4c 50 2d 45 36 00 00 00 00 00 01 00 7e 5b 1c 57 00  (PROP_BATTERY_REPORT)
[MPU] Received: 08 07 01 3b ff ff 00 00  (PROP_USBDEVICE_CONNECT - spell #32)
[MPU] Received: 08 07 01 3b ff 00 00 00  (PROP_USBDEVICE_CONNECT - spell #33)
[MPU] Sending : 06 04 03 36 00 00  (PROP_BATTERY_REPORT_FINISHED)
[MPU] Received: 08 06 03 1f 00 00 00 00  (PROP 80030019 - spell #34)
[MPU] Received: 08 07 01 3b ff 00 00 00  (PROP_USBDEVICE_CONNECT - spell #35)
[MPU] Received: 06 05 03 1e 00 00  (PROP 8003001A - spell #36)
[MPU] Sending : 06 05 03 35 01 00  (PROP_BATTERY_REPORT_COUNTER)
   295:   312.576 [LVMD] Init RCh1=0, RCh2=0
   297:   313.088 [LVCFG] LV_Initialize Aug 16 2010
   302:   313.088 [LVMD] Set RCh1=a, RCh2=19
   306:   316.160 [LVCFG] PROP_TEMP_STATUS  Temp:0, FrameRate:1
   307:   316.160 [LVCFG] PROP_LV_ACTION STOP
   311:   316.160 [LVCFG] PROP_LV_LOCK PERIMIT
   315:   316.160 [LVCFG] PROP_SHOOTING_TYPE 0
   321:   317.440 [LV] PROP_LIVE_VIEW_FACE_AF
   328:   317.952 [LVCFG] PROP_LIVE_VIEW_VIEWTYPE_SELECT 0->2
   330:   317.952 [LVCFG] PROP_LIGHT_FALLOFF_COMP 0
   369:   328.704 [PTP] PhotoStudioMode:0
   429:   334.592 [PTP] PSI DisconnectViewFinder
   558:   340.992 [PTPCOM] SetPtpTransportResources:0,3199
   571:   340.992 WriteFROM Normal:0,0
[MPU] Sending : 1c 1b 03 1d 4f 03 00 00 00 18 00 4c 50 2d 45 36 00 00 00 00 00 01 00 7e 5b 1c 57 00  (PROP_BATTERY_REPORT)
[MPU] Sending : 06 04 03 36 00 00  (PROP_BATTERY_REPORT_FINISHED)
[MPU] Received: 16 14 01 4e 00 00 00 00 00 00 00 00 00 00 00 1e 00 00 00 0f 00 00  (PROP_VIDEO_MODE - spell #37)
[MPU] Sending : 16 14 01 4e 00 00 00 00 00 00 00 00 00 00 00 1e 00 00 00 0f 00 00  (PROP_VIDEO_MODE)
[MPU] Received: 16 14 01 4e 00 00 00 00 00 00 00 00 00 00 00 1e 00 00 00 0f 00 00  (PROP_VIDEO_MODE - spell #37)
[MPU] Sending : 16 14 01 4e 00 00 00 00 00 00 00 00 00 00 00 1e 00 00 00 0f 00 00  (PROP_VIDEO_MODE)
[MPU] Received: 06 05 03 19 01 00  (PROP_TFT_STATUS - spell #39)
[MPU] Received: 06 05 03 19 01 00  (PROP_TFT_STATUS - spell #39)
[MPU] Received: 06 05 02 0a 01 00  (PROP_PERMIT_ICU_EVENT - spell #41)
[MPU] Sending : 06 05 06 11 01 00  (GUI_SWITCH)
[MPU] Received: 06 05 03 16 06 00  (PROP_BATTERY_CHECK - spell #47)
[MPU] Sending : 06 05 06 12 00 00  (GUI_SWITCH)
[MPU] Sending : 42 41 0a 08 ff 1f 01 00 01 01 a0 10 00 73 01 01 50 25 3b 01 01 00 48 04 01 08 18 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  (PD_NotifyOlcInfoChanged)
   698:   368.128 [HDMI] HPD OFF
   748:   388.352 [LVCFG] PROP_OUTPUT_TYPE 0(0) / 0
   800:   391.936 [GUI] HDMI_VIDEO_CODE 0
   911:   340.480 [STARTUP] startupInitializeComplete
   918:   340.480 [MC] cam event guimode comp. 0
   936:   342.784 [MC] cam event guimode comp. 0
   939:   343.040 [DISP] TurnOffDisplay (PUB) Type=0 fDisplayTurnOn=0
   946:   343.552 [DISP] TurnOffDisplay (PUB) Type=0 fDisplayTurnOn=0
[MPU] Sending : 06 05 04 0e 01 00  (PROP 8002000D)
[MPU] Sending : 06 05 03 16 00 00  (PROP_BATTERY_CHECK)
[MPU] Received: 06 05 04 0d 01 00  (PROP_ACTIVE_SWEEP_STATUS - spell #42)
[MPU] Sending : 06 05 04 0d 00 00  (PROP_ACTIVE_SWEEP_STATUS)
[MPU] Sending : 06 05 04 15 00 00  (PROP_DL_ACTION)
[MPU] Sending : 06 05 03 17 92 00  (PROP_EFIC_TEMP)
[MPU] Received: 06 05 03 19 01 00  (PROP_TFT_STATUS - spell #72)
  1045:   380.160 [DL ERROR] StartDL : not PrepareDL
  1060:   386.048 [DISP] TurnOffDisplay (PUB) Type=0 fDisplayTurnOn=0
[MPU] Received: 06 05 04 00 01 00  (NotifyGUIEvent - spell #44)
[MPU] Sending : 06 05 04 00 01 01  (NotifyGUIEvent)
[MPU] Received: 08 06 00 00 04 00 00 00  (Complete WaitID = 0x80020000 - spell #45)
  1065:  1459.968 [MC] PROP_GUI_STATE 1
  1086:  1459.968 [MC] cam event guimode comp. 1
  1103:  1462.528 [DISP] TurnOnDisplay (PUB) Type=0 fDisplayTurnOn=0
  1114:  1404.416 [DISP] BackLightOn
[MPU] Received: 06 05 03 19 00 00  (PROP_TFT_STATUS - spell #43)
  1115:  2437.120 [FA] FA_CreateTestImage
  1116:  2437.120 [RSC] SRM_ChangeMemoryManagementForFactory
  1132:  2437.120 [FA] hJob(0x42000064)(tv=0x73,av=0x3b,iso=0x48)
  1133:  2437.120 [FA] FA_CreateTestImage Fin
  1134:  2437.120 [FA] FA_CaptureTestImage(hJob:0x42000064)
  1135:  2437.120 [SHTC] SCS_FaSetSkeltonJob(0x42000064)
  1136:  2437.120 [FA] faSetProperty ID=0x80040000 Size=4 Value=0x4
  1141:  2437.120 [FA] Property Value (0x4 -> 0x4)
[MPU] Received: 06 05 03 07 07 00  (unknown - PROP_BURST_COUNT)
[MPU] WARNING: forced shutdown.
For clean shutdown, please use 'Machine -> Power Down'
(or 'system_powerdown' in QEMU monitor.)


Edit: here the txt/logs with the " -d debugmsg,io"
FA_CaptureTestImage.txt , FA_CaptureTestImage_2.txt and this txt/log is without " -d debugmsg,io" FA_CaptureTestImage_3_without_-d debugmsg,io.txt

@a1ex so the other suggestions you made need to be run on camera right ?
I did some dm-spy-experiments log a while ago but the cr2 capture progress was incomplete . I'll give it another try tomorrow .


reddeercity

I guess there some "FA" stuff , from the 3th log I posted
1115:  2410.496 [FA] FA_CreateTestImage
  1116:  2410.496 [RSC] SRM_ChangeMemoryManagementForFactory
  1132:  2410.496 [FA] hJob(0x42000064)(tv=0x73,av=0x3b,iso=0x48)
  1133:  2410.496 [FA] FA_CreateTestImage Fin
  1134:  2410.496 [FA] FA_CaptureTestImage(hJob:0x42000064)
  1135:  2410.496 [SHTC] SCS_FaSetSkeltonJob(0x42000064)
  1136:  2410.496 [FA] faSetProperty ID=0x80040000 Size=4 Value=0x4
  1141:  2410.496 [FA] Property Value (0x4 -> 0x4)

a1ex

Right, the MMIO_TRACE experiment was meant to be run on the camera, in order to cross-check the MMIO values from emulation with those from actual hardware, and find out their meaning. However, I think I've figured it out by looking at what the firmware expects - there is one bit checked to make sure the sensor was powered on. If that bit is not right, the firmware prints "Image Power Failure"; after that, it will (on most models) or will not (on 500D and 5D2) proceed with image capture.

FA_CaptureTestImage is currently emulated well on the following models:


Testing FA_CaptureTestImage...
    5D2: OK
    5D3: OK
     6D: OK
    50D: OK
    60D: OK
    70D: OK
   500D: OK
   550D: OK
   600D: OK
   650D: OK
   700D: OK
  1100D: OK
  1200D: OK


Also tested manually (outside the automated test suite) on 450D and 1300D. Reason: the minimal testing code is not portable enough.

EOS M and M2 are not working: apparently they fail to allocate a buffer for image capture. They also request a larger image size, compared to other 18 megapixel models. Figure out why.

EOS M2 is also a bit unique: it attempts to call some functions from the MPU first. It's also the only model that prints FA_CaptureTestImageForML.

100D and EOS M2 have something called ADTGDMA, that expects interrupt 0x37 on completion. By emulating that interrupt, FA_CaptureTestImage works on 100D, but it breaks the LiveView screenshots on EOS M2 (they look washed out after that change), so it's not committed yet.

700D and 650D were expecting some other EDMAC transfers to complete, besides the 14-bit raw data. No idea what sort of data they were expecting; I've just returned zeros.

For 5D2, this was the changeset that fixed the emulation. Unlike most other camera models, which simply checked whether the sensor is powered on (ImgPowDet) after enabling its power signal, 5D2 firmware also checked whether the sensor is off before enabling the power. So, other models could get away with a simpler emulation of the ImgPowDet register (just returning 1 was enough), while 5D2 locked up during these checks. The changeset is large because I wanted to emulate it properly on all other models, as this code also serves as documentation of what Canon hardware does, and it helped me understand this topic a little better.

The above emulation covers only the raw image capture, without any postprocessing. It won't be able to create a CR2.

reddeercity

Sound good , I'll try to get the cr2 process thought dm-spy first ,
QuoteThe cleanest way to get further is to get a MMIO log during photo capture, that includes this register, to see what values the firmware expects from there. You can do that from either dm-spy-experiments
I did notice when i cloned ml & updated to the dm-spy-experiments branch the line of code you said to add was already there static ASM_VAR uint32_t protected_region = REGION(0xC0220000, 0x010000); @ line 38 , i did make the changes in "Makefile.user.default" as you mention CONFIG_DEBUG_INTERCEPT = yCONFIG_MMIO_TRACE = y I'll report back hopefully with a complete cr2 photo capture with the full "Resources" for Lossless .

reddeercity

Holy Cow ! there so much info I can't believe it  :))
I do think I have what I need for lossless  , just got to figure out which Resources to use for compressed raw .
I won't post the interesting parts or the Logs files , even exported the digic reg's Logs and there again see valuable info for 4k/UHD
e.g. c0f06084:    10036 & c0f06088:  4f40432 That's 1:1 by the way  8)
Here the LOG's from dm-spy
dm-0000_cr2_capture.log , dm-0001_cr2_capture.log , dm-0002_cr2_capture.log , digic00-dm-spy.LOG , digic01-dm-spy.LOG

Ok I know this not the right place for this but I can't resist , here what I think could be the lossless resources
EEAF8>     RscMgr:ff8b65c4:80:01: Allocate MEM3 0 0
EEB1F>     RscMgr:ff8b6670:80:01: OK AllocateMEM3 0xBAA4C0(876544)(1)
EEBD1> FrontShtDe:ff888cc0:96:05: sdfExecuteMem1ToRawPath(5742)
EEC5E> FrontShtDe:ff888ea8:96:05: sdfExecuteMem1ToRawPath(5742)��(SemOK)
EEC9A> FrontShtDe:ff888ee0:96:05: ProcessTwoInTwoOutJpegPath(R) Start(5742)
EECE9> FrontShtDe:000965bc:00:00: *** LockEngineResources(72bed4) x17 from ffa59b1c:
EED33> FrontShtDe:00096678:00:00:      1)    10002 (read channel 0xa)
EED62> FrontShtDe:00096678:00:00:      2)        3 (write channel 0x3)
EED88> FrontShtDe:00096678:00:00:      3)        4 (write channel 0x4)
EEDAE> FrontShtDe:00096678:00:00:      4)    30000 (read connection 0x0)
EEDD8> FrontShtDe:00096678:00:00:      5)    20005 (write connection 0x5)
EEE03> FrontShtDe:00096678:00:00:      6)    20016 (write connection 0x16)
EEE26> FrontShtDe:00096678:00:00:      7)    50003 (?)
EEE48> FrontShtDe:00096678:00:00:      8)    5000d (?)
EEE69> FrontShtDe:00096678:00:00:      9)    5000f (?)
EEE8B> FrontShtDe:00096678:00:00:     10)    5001a (?)
EEEAC> FrontShtDe:00096678:00:00:     11)    80000 (?)
EEECE> FrontShtDe:00096678:00:00:     12)    90000 (?)
EEEEF> FrontShtDe:00096678:00:00:     13)    a0000 (?)
EEF10> FrontShtDe:00096678:00:00:     14)   160000 (?)
EEF33> FrontShtDe:00096678:00:00:     15)   130003 (?)
EEF58> FrontShtDe:00096678:00:00:     16)   130004 (?)
EEF7C> FrontShtDe:00096678:00:00:     17)   130005 (?)
EF007> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF048> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF07C> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF0AE> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF0DD> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF10C> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF140> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF173> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF1A1> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF1CF> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF1FD> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF227> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF250> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF27E> FrontShtDe:ff9a77d0:00:01: [CLKSAVER] ��ClockSave Out��
EF2C1> FrontShtDe:ffa59694:16:03: [TTJ][150,5742,0] RAW(5792,3804,0,14)
EF366> FrontShtDe:00096224:00:00: *** ConnectReadEDmac(0xa, 0x0), from ffa59770
EF3C5> FrontShtDe:00096224:00:00: *** RegisterEDmacCompleteCBR(0xa, 0xffa593f8 "[TTJ][%d,%d,%d] Read1CompleteCBR", 0x0), from ffa59780
EF415> FrontShtDe:00096224:00:00: *** ConnectWriteEDmac(0x3, 0x5), from ffa597f8
EF4F6> FrontShtDe:00096224:00:00: *** RegisterEDmacCompleteCBR(0x3, 0xffa9285c "[PackMem] CompleteInterrupt In %d", 0x3), from ffa92be0
EF522> FrontShtDe:ff9a47e0:00:02: [ENG] RegisterEDmacAbortCBR(3)
EF572> FrontShtDe:00096224:00:00: *** ConnectWriteEDmac(0x4, 0x16), from ffa59830
EF5D1> FrontShtDe:00096224:00:00: *** RegisterEDmacCompleteCBR(0x4, 0xffa59340 "[TTJ][%d,%d,%d] Write2CompleteCBR", 0x0), from ffa59840
EF600> FrontShtDe:ffa59888:16:03: [TTJ] START WR1:0x200807c WR2:0x1acac0f0
EF639> FrontShtDe:ffa598b4:16:03: [TTJ] START RD1:0x10000048 RD2:0x124d1864


There other resources being logged also , this may not be it , I'll continue on the ProcessTwoInTwoOutLosslessPath thread

reddeercity


a1ex

Looks good!

Were these tests run from LiveView? That's a bit too verbose; it's best if you can run them in photo mode.

Since it didn't lock up, you may now increase the MMIO range to be logged. Most of the interesting stuff (possibly all on DIGIC 4) is from 0xC0000000 to 0xC0FFFFFF; that's defined by REGION(0xC0000000, 0x1000000). This is the default configuration on the io_trace_full branch.

I recommend using io_trace_full instead of dm-spy-experiments for this stuff; it has a slightly nicer log format (with decoded microsecond timestamps) and it's able to capture a lot more stuff in the same amount of RAM. Known regressions: it's not able to run with CONFIG_DEBUG_INTERCEPT_STARTUP & CONFIG_MMIO_TRACE yet (but CONFIG_DEBUG_INTERCEPT & CONFIG_MMIO_TRACE works fine), and if the MMIO events captured require more than 16MB of storage, you will lose them all.

TLDR: looking for the same logs with the io_trace_full branch instead of dm-spy-experiments, logging a still image capture outside LiveView.

I'm unable to run these tests right now, since I'm out for holidays, far away from the city.

reddeercity

Quote from: a1ex on August 04, 2018, 09:15:41 AM
Looks good!
Were these tests run from LiveView? That's a bit too verbose; it's best if you can run them in photo mode.
Yes Liveview in photo mode without any modules loaded , I can re-run that one outside of live in photo mode .

Quote from: a1ex on August 04, 2018, 09:15:41 AM
I recommend using io_trace_full instead of dm-spy-experiments for this stuff; it has a slightly nicer log format
Ok , I ran it with "io_trace_full" and there of course is a lot of "MMIO" but I could not make much sense of it , there was no
cr2 capture process or resources like in dm-spy logs , even thou I took 2 cr2 photo (there still on the card)  here the io-trace-full log , I'll re-run this tomorrow I think I must of did something wrong .
I did run it in Liveview with photo mode , I see I should be outside of liveview in photo mode , so I'll try again later
I had CONFIG_DEBUG_INTERCEPT & CONFIG_MMIO_TRACE set to "Y" yes .





a1ex

Yes, please run them outside LiveView.

The default settings of what gets captured are different between the two branches. For example, io_trace_full has LOG_INTERRUPTS enabled, while dm-spy-experiments doesn't.

There is a line you should watch out for:

[MMIO] WARNING: lost data (try increasing buffer size)


If this line is present, I'm afraid the log is not good, since MMIO entries required more 16MB of storage and this case is not handled very well. If that happens, I just stop the experiment earlier. It's very easy to trigger this in LiveView, where you get lots of messages for every single frame, but I doubt it will happen outside LiveView, while capturing one single image.

dfort

Nice work reddeercity.

So I take it that what's good for the gander is good for the goose? Meaning what you find on the 5D2, and how you find it, will also apply to the other Digic 4 cameras like the 7D, 50D, 500D, 550D, 600D, 1100D, 1200D and maybe even the 1300D?

reddeercity

Quote from: a1ex on August 05, 2018, 05:33:38 PM
Yes, please run them outside LiveView.
Ok will do
Quote from: a1ex on August 05, 2018, 05:33:38 PM
There is a line you should watch out for:

[MMIO] WARNING: lost data (try increasing buffer size)

Yea I saw that for a belief second or 2 .

Quote from: dfort on August 05, 2018, 05:37:56 PM
Nice work reddeercity.
Thanks
Quote from: dfort on August 05, 2018, 05:37:56 PM
So I take it that what's good for the gander is good for the goose? ....
Yea sure , I never thought that what I was doing would apply to the newer D4+ cams .
I was only thinking 50D & 7D would benefit , the more the merrier I say !

reddeercity

Ran the io-trace-full outside of Liveview , here's the dm-0000_io-trace-full-outside-liveview-8-5-2018.log (for those just joining in it's from 5D2)
Looks much better ! closer to the dm-spy but many more MMIO logging , it took a long time just to quickly look though it . I did found some "resources" for what I think is lossless stuff
plus so much more , should help me with 4k/UHD dev.

6.834.203  FrontShtDe:ff9b9190:00:00: *** SDSFrontState: (1) --3--> (1)          ff88afcc (x=702ef0 z=b3e26c t=80000003)
6.834.236  FrontShtDe:ff88b008:96:05: sdsMem1ToJpegDevelop(5749)
6.834.254  FrontShtDe:ff8890a0:96:05: sdfExecuteMem1ToJpegPath(5749)
6.834.366  FrontShtDe:ff889290:96:05: ProcessTwoInTwoOutJpegPath(J) Start(5749)
6.834.434  FrontShtDe:ffa59b1c:00:00: *** LockEngineResources(72c400) x56:
6.834.465  FrontShtDe:000970ec:00:00:      1)    10002 (read channel 0xa)
6.834.485  FrontShtDe:000970ec:00:00:      2)    10003 (read channel 0xb)
6.834.500  FrontShtDe:000970ec:00:00:      3)        3 (write channel 0x3)
6.834.514  FrontShtDe:000970ec:00:00:      4)        4 (write channel 0x4)
6.834.533  FrontShtDe:000970ec:00:00:      5)    30000 (read connection 0x0)
6.834.552  FrontShtDe:000970ec:00:00:      6)    30021 (read connection 0x21)
6.834.570  FrontShtDe:000970ec:00:00:      7)    20005 (write connection 0x5)
6.834.587  FrontShtDe:000970ec:00:00:      8)    20003 (write connection 0x3)
6.834.599  FrontShtDe:000970ec:00:00:      9)    50003 (?)
6.834.610  FrontShtDe:000970ec:00:00:     10)    5000d (?)
6.834.622  FrontShtDe:000970ec:00:00:     11)    5000f (?)
6.834.633  FrontShtDe:000970ec:00:00:     12)    5001a (?)
...............................
6.835.178  FrontShtDe:000970ec:00:00:     55)   220022 (?)
6.835.191  FrontShtDe:000970ec:00:00:     56)   220023 (?)

another interesting thing
6.630.657  ShootPreDe:ff884154:95:05: WB RectH:(2960, 2992)
6.630.677  ShootPreDe:ff884174:95:05: WB RectV:(1911, 1943)

Slices ?

I'll run the dm-spy outside Liveview in photo mode also and post the log


a1ex

Looks good!

Some tips - how to "skim" this file.

SCSState aka ShootCapture, i.e. Canon's image capture task (cross-check with these notes):


cat dm-0000_io-trace-full-outside-liveview-8-5-2018.log |grep -a SCSState
6.209.844  ShootCaptu:ff9b9190:00:00: *** SCSState: (1) --1--> (2)          ff87f914 (x=640084 z=0 t=0)
6.229.970  ShootCaptu:ff9b9190:00:00: *** SCSState: (2) --2--> (4)          ff87fe5c (x=640084 z=40b2bfe0 t=25)
6.240.560  ShootCaptu:ff9b9190:00:00: *** SCSState: (4) --3--> (5)          ff880560 (x=640084 z=0 t=0)
6.273.068  ShootCaptu:ff9b9190:00:00: *** SCSState: (5) --4--> (6)          ff880600 (x=640084 z=0 t=0)
6.278.745  ShootCaptu:ff9b9190:00:00: *** SCSState: (6) --5--> (7)          ff8808cc (x=640084 z=0 t=0)
6.324.911  ShootCaptu:ff9b9190:00:00: *** SCSState: (7) --6--> (8)          ff880a1c (x=640084 z=0 t=0)
6.442.677  ShootCaptu:ff9b9190:00:00: *** SCSState: (8) --10--> (8)          ff88118c (x=640084 z=0 t=0)
6.562.736  ShootCaptu:ff9b9190:00:00: *** SCSState: (8) --7--> (1)          ff880bd8 (x=640084 z=0 t=0)


"FPS" timers during still image capture, also raw resolution registers:

cat dm-0000_io-trace-full-outside-liveview-8-5-2018.log | grep -a 0xC0F060
6.236.948  ShootCaptu:ff9a5630:MMIO : [0xC0F06008] <- 0x05DB05DB
6.236.950  ShootCaptu:ff9a5630:MMIO : [0xC0F0600C] <- 0x05DB05DB
6.236.951  ShootCaptu:ff9a5630:MMIO : [0xC0F06010] <- 0x000005DB
...
6.273.667  ShootCaptu:ff9a5630:MMIO : [0xC0F06084] <- 0x00010037
6.273.668  ShootCaptu:ff9a5630:MMIO : [0xC0F06088] <- 0x0EDD0B87
...
6.285.858  ShootCaptu:ff9a5630:MMIO : [0xC0F06014] <- 0x00000EDC


"Plain" diagnostic log (without MMIO and interrupts):

cat dm-0000_io-trace-full-outside-liveview-8-5-2018.log |grep -av 'MMIO\|>>> INT\|<<< INT'


IMGPOWDET register (0xC022001C) and InitializePcfgPort register (my guess: 0xC0F01010):

cat dm-0000_io-trace-full-outside-liveview-8-5-2018.log |grep -a '0xC022001C\|0xC0F01010'
6.210.352  ShootCaptu:ff9b72e4:MMIO : [0xC022001C] -> 0x00000020
6.219.347  ShootCaptu:ffa36154:MMIO : [0xC0F01010] <- 0x00200000
6.229.294  ShootCaptu:ff9b72e4:MMIO : [0xC022001C] -> 0x00000021


The emulation matches these values :D

reddeercity

That's great ! Just finish running "dm-spy-experimental" Cr2 capture Log from outside Liveview , notice there more Jpeg stuff going on .
Here the dm-0001_dm-spy_outside_liveview_cr2_capture.log

a1ex

May I ask for a similar log while reviewing an image, with the io_trace_full branch? That should cover JPEG decoding and might be easier to understand.

Also getting closer to emulating a CR2 image capture. Emulation reaches sdfExecuteMem1ToRawPath (FrontShtDevelop), attempts to configure JPCORE and gets stuck requesting image data from EDMAC channel #3, connection 5. I believe that's where the firmware expects LJ92 data from the lossless encoder.

reddeercity

Just for the hell of it I run the dm-spy (outside Liveview) again but I set the cam to sRaw
47755> FrontShtDe:ffa596e8:16:03: [TTJ][150,5756,0] MRAW(3872,2574,0,16)
Here the dm-0002_dm-spy-sRaw_Cr2_Capture_outside_liveview.log
Here the MRaw 3872x2574 Cr2_MG_8745.CR2

Thought while I was at it , I run the dm-spy in Liveview while recording H264 .mov
it seems base things from 5616x3744 , nice to bypass the rez re-size and have it  5.6k H264  ;)
dm-0003_dm-spy-H264_recording_in_Liveview.log