Canon 80D

Started by ariznaf, June 02, 2016, 09:27:03 AM

Previous topic - Next topic

0 Members and 2 Guests are viewing this topic.

a1ex

Awesome! It saved all of that without crashing? :)

CONFIG_80D: it should be defined by the Makefiles. If I compile the same code on 5D4, for example, it will refuse to run. If I write some gibberish into the CONFIG_80D block from log-d6.c, I get a compile error (without having to define CONFIG_80D manually anywhere).

Back to cleaning up io_trace.

sombree

Yep, no crash, just a little longer camera start up :)
As for CONFIG_80D - you're right, it's defined by the Makefile.

a1ex

OK, io_trace code committed. Whew, this was hard!

Compile with: make clean && make CONFIG_MMIO_TRACE=y

If it locks up:
- try previous changesets
- reduce the logged range (for example, try logging from 0xC0220000, size 0x1000)
- give me as many details about the crash as you can (it's very hard to debug)

Fingers crossed.


a1ex

Make sure you compile with CONFIG_MMIO_TRACE=y on the command line. There should be 2 log files.

If in doubt, run "make clean" first (updated the command), as the build system doesn't know it needs to recompile if you change only the options. It only recompiles if you edit source files.

sombree

It worked out of box :D
mmio log without lens
mmio log with lens attached
another one - with a little exercise - took a photo, fiddled with a touchscreen, changed iso etc.

a1ex

Really nice! These files contain the ultimate reference data for DIGIC 6!

Previously, I had to guess many of these values, from what the code seemed to expect. That took me probably months of trial and error (well, years with the fragmentation, as I didn't work only on this). You may ask - why didn't I start with this from the beginning? Err... back then, I simply did not understand how computers work, well enough to write the MMIO tracing code. I've learned it from... all of that trial and error (not only from the 80D firmware, but from investigating about 40 EOS models from different generations). I've tried to summarize what I've learned here, but it's probably a bit too advanced for beginners.

Anyway, let's try logging some more address ranges:

- from 0xBFE00000, size 0x200000 (expecting some activity from GuiMainTask)
- from 0xEE000000, size 0x1000000 0x2000000 (no activity in QEMU; unused?)
- from 0xA0000000, size 0x40000000 (expecting all MMIO activity, i.e. C, D and BFE ranges) (nevermind, invalid range)

I'll be back with a guide on how to interpret these huge logs.

sombree

from 0xBFE00000, size 0x200000  - camera locks up with Err70, no log is saved. Edit: sometimes camera locks up with Err70 but led still blinks as it's supposed to.
from 0xEE000000, size 0x1000000 - MMIO log looks empty - log.
from 0xA0000000, size 0x40000000 - camera locks up without any error, no log is saved.

Ant123

Does MMIO trace work in LiveView mode?

On EOS M3 io_trace causes crash in Rec mode.

sombree

Few times it didn't work in regular (photo) LiveView - on-screen image was garbled and there was no log. Right now I've tried again and no problem at all, both in photo and video LV (log).

Ant123

Quote from: sombree on February 02, 2019, 09:58:41 PM
from 0xBFE00000, size 0x200000  - camera locks up with Err70, no log is saved.

0xBFF00000 memory region contains message buffers shared with MZRM core. So probably io_trace code is not fast enough for transfers caused by memcpy.

sombree

After builiding with -O2 (instead of default -Os) I was able to get some partial logs:
from 0xBFE00000, size 0x200000 - log
from 0xA0000000, size 0x40000000 - camera locks up with Err60, no log is saved.

Edit:
I checked from 0xA0000000, size 0xFFFFFFF - camera doesn't lock up and MMIO log is empty (unused range?).

a1ex

Indeed, access in the BFE region is done with highly optimized code, memcpy and memcpy-like This is where io_trace struggles.

Possible reasons for crash:
- Too slow (noticeable with a huge number of events). In this case, using a lower frame rate for LiveView usually helps.
   - compiler optimization: the io_trace code is handwritten assembly (i.e. not affected at all)
   - maybe the other logging code (written in C) was improved by -O2, but I don't expect a big difference
   - I'd be surprised if the optimization level really helped in a repeatable way (i.e. consistently crashing with -Os and consistently working with -O2)
   - either way, these partial logs were really helpful, so whatever you did to capture them, it was good

- Re-execution context (register contents) slightly different. This could affect the outcome of the original code (the path it takes). My tracing code works by:
   - disallowing memory access in the logged area
      - this camera has a memory protection unit with 8 memory regions (from 0 to 7)
      - 80D firmware uses just the first 7 (likely true on other D6 models)
      - so, I could configure the last memory region (which has the highest priority) to cover the logged area and to disable the read/write permissions
   - this will cause a data abort exception for the instruction trying to read or write in the logged range
   - this instruction will have to be re-executed:
      - I need to log the result of that instruction (i.e. return value from a MMIO register), so I can't just jump back into the original code
      - therefore, I'm copying the original instruction in the middle of my data abort handler
      - before re-executing it, I disable the memory protection region, sync the caches and restore context (original registers)
      - then I re-enable the memory protection, to keep catching further MMIO reads/writes
   - this lets me to log stuff both before and after the trapped instruction
   - registers in data abort mode are not exactly the same as in user mode (SP and LR differ)
   - this is not usually a problem in regular MMIO code, but highly optimized code like memcpy does use LR as a general-purpose register; maybe also SP
   - this edge case (or corner case, if you prefer) is not handled well by io_trace
- other bugs in the low-level io_trace code, that I'm not aware of

The partial log shows a very important hint: at address 0xBFE00000, the firmware writes 0 or 1, but always reads 0. That means this address (possibly the entire range) behaves somewhat like MMIO, rather than like simple memory. It's probably shared memory, where the secondary cores (like Omar and Zico) are writing, too. Still, as long as we are not emulating these secondary cores, we need to model their behavior. If no code is executed by the main core from this memory range, modeling it as MMIO (rather than regular memory) is probably the way to go.

What to do about logging the activity in this range?
- fix the io_trace code to re-execute the trapped instruction with the original SP and LR
- replace memcpy with a slower function (easier to log with current code)
- try to log smaller regions

I'll look into the first two. You could attempt to log from 0xBFF00000, size 0x100000 (i.e. the upper half, used by MZRM). The lower half (0xBFF00000, size 0x100000) appears to be used by Omar.

In QEMU, logging the BFF range gives over 12000 MMIO events, starting with:

4.494781  GuiMainTas:fe64ee06:MMIO : [0xBFF20000] <- 0x00000106
4.494782  GuiMainTas:fe64ee0a:MMIO : [0xBFF20004] <- 0x8201FC60
4.495039  GuiMainTas:fe64ee0e:MMIO : [0xBFF20008] <- 0xA0FFFF01


It still contains highly optimized memcpy-like code, so don't worry if it won't work out of the box.




Size 0xFFFFFFF means, according to Cortex R4 TRM page 123:
- enabled
- region size: 4 GB
- all sub-regions disabled

In other words, it's effectively disabled (it won't log anything).

Size must be power of 2 (p. 124). Start address must be multiple of size (p. 178).




Noticed a typo - from 0xEE000000, the size should have been 0x2000000. Either way, there's no activity in QEMU on this address range. This comes from the startup configuration:

FE0258E4: MCR p15,0,Rd,cr6,cr2,0:       RGNR <- 0x5       
FE0258EC: MCR p15,0,Rd,cr6,cr1,0:      DRBAR <- 0xEE000000
FE0258F4: MCR p15,0,Rd,cr6,cr1,4:      DRACR <- 0x329      (P:RW U:RW; Inner Write-back, write-allocate; Outer Write-back, write-allocate; Non-shared)
FE0258FC: MCR p15,0,Rd,cr6,cr1,2:       DRSR <- 0x31       (0x2000000)





@Ant123: if you managed to run this on the M3, I'd like to see some logs :D




Found a slightly better way to merge the two logs:


cat DEBUGMSG.LOG MMIO.LOG | ansi2txt | sort -k 1n -s > STARTUP.LOG


Still, the first few lines (those timestamped with 0.000000, i.e. before the microsecond timer was started by Canon firmware) won't be merged in the right order. This is addressed in the full io_trace code (io-trace-full branch). I might be tempted to run that, too; just need to find the full set of stubs to compile the regular ML codebase. Easy coding task, if anyone wants to help.

Currently trying to find a way to annotate these huge logs (i.e. what each register does).

sombree

Sure:
0xBFF00000, size 0x100000 - log
Fun fact - with this base and size camera doesn't lock up (i.e. I can take a photo) but main screen doesn't work at all. It's just completely black. Secondary screen still works.

a1ex

Managed to restore the original LR, so memcpy & related routines should no longer be affected, in theory. The register values reported in these highly optimized routines will still be bogus, but now I don't expect the io_trace code to change the outcome of the original routine. I've tested the change in QEMU on memcpy (0x80007C8C) and bzero32 (0x80007E84), with a buffer size of 0x100000. With previous io_trace code, 1/4 of the copied (or zeroed) data was corrupted (because it was written from LR). With current io_trace code, the memory contents was correct after copying / zeroing.

Whether this change will help with logging the tricky ranges (BFE/BFF)... I don't know. Let's find out.

The latest code also logs LR for each MMIO event. That's very useful information to have in some cases (and still insufficient in others, where a stack trace would be helpful). For this reason, I'd also like some new general-purpose logs after the latest changes, i.e. a plain startup log and another one with exercising (photo capture, LiveView).




P.S. @Ant123 is making great progress understanding the display routines on DIGIC 6 - here and here.

sombree

It works :D
from 0xBFE00000, size 0x200000: regular and with exercising
from 0xC0000000, size 0x20000000: regular and with exercising
Btw. camera boots autoexec.bin a little faster than before.

a1ex

Really nice!

Annotated versions for the regular (C0000000/20000000) logs:
STARTUP.log (plain startup, 21MB)
STARTUP-ph.log (with exercise = photo capture, 24 MB)

An older log, with LiveView activity, but no LR:
LV.log (75 MB)




Let's look for interesting stuff.

FPS registers and raw image size (discussed before):

cat STARTUP-ph.log | grep MMIO | grep '0xD0006008\|0xD0006014\|0xD0006800\|0xD0006804'
2.797276  ShootCaptu:fe51786f:fe51786b:MMIO : [0xD0006800] <- 0x0002000E: start row/column for image capture
2.797298  ShootCaptu:fe51786f:fe51786b:MMIO : [0xD0006804] <- 0x0FDB0320: end row/column => 6288x4057
2.838859  ShootCaptu:fe51786f:fe51786b:MMIO : [0xD0006008] <- 0x03030303: FPS timer A: 772 [ wait a minute, 772 * 8 = 6176 < 6288, why?! ]
2.838921  ShootCaptu:fe51786f:fe51786b:MMIO : [0xD0006014] <- 0x00000FDD: FPS timer B: 4062 [ 27 MHz / 772 / 4062 = 8.6 FPS?! ]



cat LV.log | grep MMIO | grep '0xD0006008\|0xD0006014\|0xD0006800\|0xD0006804'
8.577698         Evf:fe51786e:MMIO : [0xD0006008] <- 0x02D102D1: FPS timer A: 722
8.577759         Evf:fe51786e:MMIO : [0xD0006800] <- 0x0003000E: start row/col
8.577779         Evf:fe51786e:MMIO : [0xD0006804] <- 0x02B1021A: end row/col: 2096x1372
8.578004         Evf:fe51786e:MMIO : [0xD0006014] <- 0x000004DE: FPS timer B: 1247/1248 (changes often)
8.719223         Evf:fe51786e:MMIO : [0xD0006014] <- 0x000004DF: FPS between 29.965 and 29.988 (averaged: 29.976)





Display buffer. From bootloader configuration (eos.c, disp_direct.c), the relevant registers are:
- 0xD2013800, 0xD201381C: display resolution
- 0xD2030108: BMP VRAM address << 8
- 0xD20139A8: palette address << 4
- 0xD20139A0: palette confirm

Can we find any of these in our logs?


cat STARTUP.log | grep '0xD2013800\|0xD201381C\|0xD2030108\|0xD20139A8\|0xD20139A0'
0.420055     Startup:fe1e83d9:fe18b2bd:MMIO : [0xD2013800] -> 0x00000000; DIGIC6: Display resolution
1.309242   DispDCtrl:fe1e8409:fe198133:MMIO : [0xD2013800] <- 0x01E002D0; DIGIC6: Display resolution
1.309634   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x00019018; DIGIC6: BMP VRAM
1.309651   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x0001882E; DIGIC6: BMP VRAM
1.510903   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x00019018; DIGIC6: BMP VRAM
1.510924   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x0001882E; DIGIC6: BMP VRAM


0x01E002D0 is 720x480. So far, so good - most other Canons use this resolution.

VRAM address - cross-check with:
Quote from: Ant123 on January 17, 2018, 05:45:48 PM
two uyvy buffers at 0x41785B00, 0x41901800

0x40000000 is for disabling caches, value written to 0xD2030108 is shifted by 8, so... UNCACHEABLE(0x19018 << 8) is exactly 0x41901800. It matches!

The other number doesn't match, but let's look at the other log:

cat STARTUP-ph.log | grep '0xD2013800\|0xD201381C\|0xD2030108\|0xD20139A8\|0xD20139A0'
2.397632   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x0001785B; DIGIC6: BMP VRAM
... (a few other values) ...


There you have it.

Now, let's hack the camera:


#define HALFSHUTTER_PRESSED MEM(0x5CAC)

/* test code, somewhere in dump_task */
int offset = 0;
while(1)
{
    if (HALFSHUTTER_PRESSED)
    {
        MEM(CARD_LED_ADDRESS) = LEDON;
        MEM(0xD2030108) = 0x00019018 + offset++;    /* try other values, like 0x1234, random etc */
    }
    else
    {
        MEM(CARD_LED_ADDRESS) = LEDOFF;
    }

    msleep(50);
}


Expected outcome:
- SD card LED turning on when pressing shutter halfway, and off when releasing it
- gibberish on the screen, possibly shifting the main image, triggered by half-shutter press.
- image back to normal when entering Canon menu or otherwise changing the GUI mode.

Theory:
- there is a frame buffer in the main RAM (like before, just with a different image format: uyvy; previous models were palette-based)
- the display hardware knows about it from a MMIO register (0xD2030108) (like before, just different register)
- contents of that frame buffer is rendered on a secondary CPU (previous models were rendering the bitmap overlay on the main CPU)
- the frame buffer address only changes when the GUI subsystem goes into some different mode (e.g. from shooting mode to Canon menu)
- we *might* be able to redirect the display buffer anywhere else in the RAM and write what we want there (let's see the outcome of that hack)

sombree

It works too :D
With 0x1234 LiveView (both in photo and video mode) screen flashes green with shutter pressed halfway. After that main screen's background changes from black to last LV frame when shutter is pressed halfway. Also LED blinks as it's supposed to :)
Edit:

srsa

Quote from: a1ex on February 05, 2019, 11:28:49 PM
Theory:
- there is a frame buffer in the main RAM (like before, just with a different image format: uyvy; previous models were palette-based)
On D6 PowerShots, the overlay uses two buffers at the same time: one uyvy plus one "opacity" (1 byte per pixel). The opacity buffers are usually located close to the uyvy ones. If these cameras have the same display config, and you're planning to write to the uyvy buffers, you'll need to write the opacity buffers too.
Quote- the frame buffer address only changes when the GUI subsystem goes into some different mode (e.g. from shooting mode to Canon menu)
On newer D6 Powershots, buffers are switched continuously when there are animations on screen.

a1ex

Thanks srsa for the hints.

@sombree: I'd like a full RAM/ROM dump captured in the same session as MMIO logging, covering PLAY mode and Canon menu.

That is, the following lines should be called right *after* log_finish():

    dump_file("ROM1.BIN", 0xFC000000, 0x02000000);
    dump_file("ATCM.BIN", 0x00000000, 0x00004000);
    dump_file("BTCM.BIN", 0x80000000, 0x00010000);
    dump_file("RAM4.BIN", 0x40000000, 0x40000000);
    dump_file("BFE0.BIN", 0xBFE00000, 0x00200000);  // if these cause lock-up, skip them
    dump_file("DFE0.BIN", 0xDFE00000, 0x00200000);


Ideally, the main memory should be zeroed out at startup, too (CONFIG_MARK_UNUSED_MEMORY_AT_STARTUP like before, but without the logging code from minimal-d6.c).

And, as soon as the camera starts (i.e. during the LED blinks at the beginning of dump_task):
- press PLAY (make sure you've got a valid image there)
- press MENU to enter Canon menu
- leave the camera in this state until it completes the dump.




Misc small questions, easy to figure out with the camera in your hands:

- is D2030108 readable? [ print MEM(0xD2030108) to find out ]
- what is C8200008? max value 10000 decimal, maybe some timer? [ print MEM(0xC8200008) many times in a loop to find out ]




I've looked again into Omar (secondary core, called Eeko in DIGIC 5). Previously, this was not essential for emulating the basics. Now... I'm afraid it might be.

I was hoping to get away with emulating just the communication between the two, but...

Quote from: a1ex on September 14, 2018, 10:03:48 AM
80D 102:
dd if=ROM1.BIN of=00000000.BIN bs=1 skip=$((0x888824)) count=$((0x4700))
dd if=ROM1.BIN of=80000800.BIN bs=1 skip=$((0x88CF2C)) count=$((0xE258))
dd if=ROM1.BIN of=01AC0000.BIN bs=1 skip=$((0x89B18C)) count=$((0xADE8))
dd if=ROM1.BIN of=01AE0000.BIN bs=1 skip=$((0x8A5F7C)) count=$((0x2898F0))

The last two segments are shared with the main memory. The first two seem to be private. Not sure how much memory is actually shared and how much is available for this core only.

Memory regions configured:

00000000 - FFFFFFFF: background region                  ACR=0x121  (P:RW U:--; Inner Write-back, write-allocate; Outer Non-cacheable; Non-shared)
40000000 - 7FFFFFFF: uncacheable                        ACR=0x12C  (P:RW U:--; Inner Non-cacheable; Outer Write-back, write-allocate; Shared)
BFE00000 - BFFFFFFF: shared with main CPU and Zico?     ACR=0x124  (P:RW U:--; Inner Non-cacheable; Outer Non-cacheable; Shared)
C0000000 - FFFFFFFF: MMIO area                          ACR=0x1105 (P:RW U:--; Shareable device; Shareable; Execute never)
DFE00000 - DFFFFFFF: another shared area?               ACR=0x124  (P:RW U:--; Inner Non-cacheable; Outer Non-cacheable; Shared)
EC000000 - EFFFFFFF: ?!?                                ACR=0x121  (P:RW U:--; Inner Write-back, write-allocate; Outer Non-cacheable; Non-shared)
FC000000 - FDFFFFFF: main ROM?                          ACR=0x121  (P:RW U:--; Inner Write-back, write-allocate; Outer Non-cacheable; Non-shared)


It uses 4 bidirectional communication channels + a few others (control?) + interrupts. Messages exchanged are - so far - 2 x 32-bit each. They share memory addresses very often; this might require emulating both cores at the same time. I might be tempted to run io_trace on this core, too. Not a trivial task, but doable... given enough time to sit down and debug.

This core runs a lightweight DryOS (starts at 0, cstart at 4a4, init_task at 1180, task_create at 80003830, current_task at 1AC0058 etc). It handles image-related tasks, but also... networking!


[        init:01b865dd ] task_create(EvShel, prio=18, stack=8000, entry=1b8651d, arg=0)
[        init:80005143 ] task_create(DbgMgr, prio=1f, stack=0, entry=800050bf, arg=1e013b4)
[        init:80005143 ] task_create(SystemTask, prio=d, stack=400, entry=800050bf, arg=1e01ba8)
[        init:8000559f ] task_create(PComSysTask, prio=e, stack=1000, entry=1b8ae07, arg=0)
[        init:80005143 ] task_create(ShtCap, prio=f, stack=1000, entry=800050bf, arg=1e01d64)
[        init:80005143 ] task_create(ShtCapFpga, prio=f, stack=1000, entry=800050bf, arg=1e01d9c)
[        init:80005143 ] task_create(LvCap, prio=f, stack=1000, entry=800050bf, arg=1e01ef4)
[        init:80005143 ] task_create(ShtDev, prio=10, stack=1000, entry=800050bf, arg=1e0204c)
[        init:80005143 ] task_create(ShtDist, prio=10, stack=1000, entry=800050bf, arg=1e02084)
[        init:80005143 ] task_create(ShtSs, prio=10, stack=1000, entry=800050bf, arg=1e020bc)
[        init:80005143 ] task_create(LvDev, prio=10, stack=1000, entry=800050bf, arg=1e02274)
[        init:80005143 ] task_create(ShtVfx, prio=11, stack=1000, entry=800050bf, arg=1e025ac)
[        init:80005143 ] task_create(FmidCtrl, prio=12, stack=1000, entry=800050bf, arg=1e02740)
[        init:8000559f ] task_create(PComAppTask, prio=18, stack=1000, entry=1b8ac03, arg=0)
[        init:80005143 ] task_create(Color, prio=1d, stack=8000, entry=800050bf, arg=1e02a14)
[        init:80005143 ] task_create(MvRsz, prio=18, stack=400, entry=800050bf, arg=1e02a84)
[        init:80005143 ] task_create(MvThmRsz, prio=18, stack=400, entry=800050bf, arg=1e02abc)
[        init:80005143 ] task_create(MvThmEnc, prio=18, stack=400, entry=800050bf, arg=1e02af4)
[        init:80005143 ] task_create(MvHist, prio=18, stack=400, entry=800050bf, arg=1e02b2c)
[        init:80005143 ] task_create(MvTestChart, prio=18, stack=800, entry=800050bf, arg=1e02b64)
[        init:80005143 ] task_create(DP, prio=18, stack=400, entry=800050bf, arg=1e02d70)
[        init:01ba12fd ] task_create(PCNCom[Common], prio=1c, stack=0, entry=1ba11c7, arg=40d74a24)
[      EvShel:8000559f ] task_create(LowConsole, prio=19, stack=800, entry=1b87757, arg=0)
[      EvShel:8000559f ] task_create(ConsoleSvr, prio=18, stack=800, entry=1b87365, arg=0)



K350_OMAR[1]> ?
[CUStop]
[dmprint]
[grep]
[taskShow]
[drysh]
[CUStart]
[dmstore]
[CUPrint]
[dump]
[PCMCheck]
[memShow]

Dry[OMAR]> ?
[Kern]
extask  memmap  meminfo  mkcfg  dminfo  exobjinfo  stdlibcfg  sw  sysvers  xd
xm  prio  resume  suspend  release  sem  mutex  event  mq  exit
[DryNet]
init  cmd  wprd  ntbase  dryend  sdclk
[NetPComMem]
npcm

Dry[OMAR]> memmap
00000000 : DRY_EXCEP_VECTOR
00000000 : ATCM_START_ADDR
00008000 : ATCM_END_ADDR
80000000 : BTCM_START_ADDR
80010000 : BTCM_END_ADDR
01a00400 : heap start
           0x00056e9c(355996)
01a5729c : heap end
01a5729c : DRY_SYS_OBJS_START
           0x00004d64(19812)
01a5c000 : DRY_SYS_MEM_START
           0x00064000(409600)
01a00000 : DRY_ERREX_STACK_START
           0x00000400(1024)
01a00400 : DRY_ERREX_STACK
80000000 : DRY_EXCEP_STACK_START
           0x00000800(2048)
80000800 : DRY_EXCEP_STACK

Dry[OMAR]> exobjinfo
          MAX  COUNT   PEAK
task       68     25     25
sem       107     23     23
event     128      1      1
mq        112     24     24
mb          0      0      0
mutex      65      0      0
cond       64      0      0
timer       4      0      0
Timer1m    10      0      0
UTimer     16      0      0

Dry[OMAR]> init         # from DryNet
Dry[OMAR]> ?            # new commands appear
[Kern]
extask  memmap  meminfo  mkcfg  dminfo  exobjinfo  stdlibcfg  sw  sysvers  xd
xm  prio  resume  suspend  release  sem  mutex  event  mq  exit
[DryNet]
init  cmd  wprd  ntbase  dryend  sdclk
[NetPComMem]
npcm
[WELL]
nell-attach  nell-detach  nell-wakeup  nlog  up  down  stat  scan  join
leave  wset  wget  wep  w12get  w12set  crypto  elog  uap
[Test]
time  count  mktest  iotest  chkspi
[Net]
arp  mbufs  route  ifconfig  netstat  ping  timer  netvers



Updated annotations with some low-level details (grep for Omar):

Quote from: a1ex on February 05, 2019, 11:28:49 PM
STARTUP.log (plain startup, 21MB)
STARTUP-ph.log (with exercise = photo capture, 24 MB)
LV.log (75 MB)

sombree

I have tried logging 0xD2030108 like this:
    DryosDebugMsg(0, 15, "MEM(0xD2030108) =");
    DryosDebugMsg(0, 15, MEM(0xD2030108));
    DryosDebugMsg(0, 15, "MEM(0xD2030108) = %d", MEM(0xD2030108));

but I'm not sure if that worked.

0xC8200008 was logged with this:
static void C8200008_log(int times, int delay)
{
    for (int i = 0; i < times; i++)
    {
        DryosDebugMsg(0, 15, "MEM(0xC8200008) %d / %d = %d", i, times, MEM(0xC8200008));
        msleep(delay);
    }
}

C8200008_log(100, 20);
I think it worked - you can see C8200008 values in log.

Also I was able to make a full ROM/RAM dump (camera on -> PLAY mode with valid image -> menu) - log.

a1ex

0xD2030108: no, it's not readable. It's not unusual - many MMIO registers in Canon hardware are write-only. They even use a mirror in the main memory for some registers they may want to read back (sht_mirror).

0xC8200008: it's not timer; it goes back and forth. In previous logs, it covers a wider range (min. 319, max 9943). Firmware subtracts it from 10000, but I'm not sure what exactly it does with the result.

Full RAM/ROM dump: can you also make one with the default MMIO range (C0000000/20000000) and CONFIG_MARK_UNUSED_MEMORY_AT_STARTUP defined?

sombree

Hm, with current tree there is no log when CONFIG_MARK_UNUSED_MEMORY_AT_STARTUP is defined. I double checked with fresh, clean tree.
C0000000/20000000 without CONFIG_MARK_UNUSED_MEMORY_AT_STARTUP defined - log.

a1ex

Decoded the log - sort of:

cat DEBUGMSG.LOG MMIO.LOG | sort -k 1n -s | ansi2txt > STARTUP.LOG
cat STARTUP.LOG | grep -E 'PRESS.*BUTTON|0xD203010' | grep -v PRESS_BUTTON_SOMETHING

1.449652   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x00000002
1.449655   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x00020077
1.449657   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x00019018 ; overlay, 960x540 UYVY, see reply #251
1.449670   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x00000009
1.449672   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x0002003B
1.449674   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x0001882E ; opacity, FF everywhere, 960x540 bytes
1.650063   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x00000006
1.650065   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x00020077
1.650067   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x00019018 ; overlay
1.650081   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x0000000C
1.650084   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x0002003B
1.650086   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x0001882E ; opacity
2.792424     CtrlSrv:fe5cf0af:83:03: IDLEHandler PRESS_PLAY_BUTTON
2.850511   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x00000002
2.850513   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x00020077
2.850515   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x0001785B ; overlay #2 (black)
2.850531   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x00000009
2.850533   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x0002003B
2.850535   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x00017071 ; opacity #2 (FF everywhere)
3.137014   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x0000009F
3.137017   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x0002005B
3.137019   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x003F8170 ; image, 736x480 UYVY, 16px bar on the right
3.162051   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x00000006
3.162053   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x00020077
3.162056   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x00019018 ; overlay
3.162070   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x0000000C
3.162072   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x0002003B
3.162074   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x0001882E ; opacity
4.191632     CtrlSrv:fe41bf47:83:03: DlgPlayMain.c PRESS_MENU_BUTTON
4.191660     CtrlSrv:fe5ceacb:83:03: IDLEHandler PRESS_MENU_BUTTON
4.219492   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x00000002
4.219494   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x00020077
4.219496   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x0001785B ; overlay #2
4.219513   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x00000009
4.219515   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x0002003B
4.219517   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x00017071 ; opacity #2
4.331596   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x00000006
4.331599   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x00020077
4.331601   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x00019018 ; overlay
4.331617   DispVCtrl:fe2085e7:fe2085e3:MMIO : [0xD2030100] <- 0x0000000C
4.331618   DispVCtrl:fe2085ef:fe2085e3:MMIO : [0xD2030104] <- 0x0002003B
4.331620   DispVCtrl:fe2085f1:fe2085e3:MMIO : [0xD2030108] <- 0x0001882E ; opacity




Misc notes:
- both the bitmap overlay and the image use the same format (YUV422)
- previously, bitmap overlay was palette-based and image buffer was YUV422, so we used to call these BMP and YUV VRAM (or BMP and IMG VRAM)
- there are two bitmap buffers; they get overwritten (i.e. whatever was displayed during image playback is no longer in the RAM dump)
- bitmap overlay uses an opacity buffer (FF everywhere so far), see srsa's message
- bitmap overlay, opacity buffer and image VRAM are all set via [0xD2030108]
- bitmap overlay is always preceded by: [0xD2030104] <- 0x00020077
- opacity buffer is always preceded by: [0xD2030104] <- 0x0002003B
- image buffer is (always?) preceded by: [0xD2030104] <- 0x0002005B
- bitmap image in bootloader (palette-based) is preceded by: [0xD2030104] <- 0x0002002C (and [0xD2060044] <- 0x0002002C in DIGIC 7)

This might explain the result of the hack - we have modified the address of the opacity buffer. At 0x123400, the RAM dump has a large memory area filled with 0x55.

@sombree: can you perform the same procedure (full RAM/MMIO dump), but leave the camera in PLAY mode? Make sure you also have some overlays on the test image (press INFO to toggle them). No need to press MENU this time.

Regarding CONFIG_MARK_UNUSED_MEMORY_AT_STARTUP - if you define this, but delete the associated code block from minimal-d6.c, it should have no effect on the logging process. I'm only interested in what this option does in reboot.c (during early startup, before launching Canon firmware). It will have some effect on the RAM dump.




Edit - got another idea for logging BFE and C/D ranges at the same time:

static ASM_VAR uint32_t protected_region_base = REGION_BASE(0x80000000);
static ASM_VAR uint32_t protected_region_size = REGION_SIZE(0x80000000) | 0xC700;


Translation:

001CDA9C: MCR p15,0,Rd,cr6,cr2,0:       RGNR <- 0x7       
001CDAA4: MCR p15,0,Rd,cr6,cr1,0:      DRBAR <- 0x80000000
001CDAAC: MCR p15,0,Rd,cr6,cr1,2:       DRSR <- 0xC73D     (0x80000000)
Subregion 80000000 - 8FFFFFFF: disabled
Subregion 90000000 - 9FFFFFFF: disabled
Subregion A0000000 - AFFFFFFF: disabled
Subregion B0000000 - BFFFFFFF: enabled
Subregion C0000000 - CFFFFFFF: enabled
Subregion D0000000 - DFFFFFFF: enabled
Subregion E0000000 - EFFFFFFF: disabled
Subregion F0000000 - FFFFFFFF: disabled


Can get a full RAM dump and MMIO log with the above configuration? Otherwise, same as before (camera left in PLAY mode, some overlays displayed on top of the test image, CONFIG_MARK_UNUSED_MEMORY_AT_STARTUP defined and the corresponding code block deleted from minimal-d6.c).




Then, let's modify the display hack like this (with the same boilerplate code as before):

MEM(0xD2030100) = 2;  /* unsure; 2 or 6 */
MEM(0xD2030104) = 0x20077; /* meaning: we are going to change the bitmap buffer address */
MEM(0xD2030108) = /* address of new bitmap buffer, e.g. "0x00019018 + offset++", or 0x300000, or 0x280000, or 0x2AB000, or something allocated dynamically etc */





Another version of the display hack, this time attempting to modify the display buffer contents directly:


    while(1)
    {
        MEM(CARD_LED_ADDRESS) = LEDON;
        msleep(500);
        MEM(CARD_LED_ADDRESS) = LEDOFF;
        msleep(500);

        uint32_t * vram1 = (uint32_t *) 0x1901800;
        uint32_t * vram2 = (uint32_t *) 0x1785B00;
        for (int i = 0; i < 540; i++)
        {
            vram1[i + i * 960/2] = 0x46ff465e;
            vram2[i + i * 960/2] = 0x6d216d4b;
        }
    }

sombree

C0000000/20000000 with CONFIG_MARK_UNUSED_MEMORY_AT_STARTUP in PLAY mode with overlay - log
0x80000000/0x80000000|0xC700 with CONFIG_MARK_UNUSED_MEMORY_AT_STARTUP in PLAY mode with overlay - log

MEM(0xD2030100) = 2;  /* unsure; 2 or 6 */
MEM(0xD2030104) = 0x20077; /* meaning: we are going to change the bitmap buffer address */
MEM(0xD2030108) =  0x00019018 + offset++; /* address of new bitmap buffer, e.g. "0x00019018 + offset++", or 0x300000, or 0x280000, or 0x2AB000, or something allocated dynamically etc */

gives this when shutter is halfpressed - link to short slow motion clip


    while(1)
    {
        MEM(CARD_LED_ADDRESS) = LEDON;
        msleep(500);
        MEM(CARD_LED_ADDRESS) = LEDOFF;
        msleep(500);

        uint32_t * vram1 = (uint32_t *) 0x1901800;
        uint32_t * vram2 = (uint32_t *) 0x1785B00;
        for (int i = 0; i < 540; i++)
        {
            vram1[i + i * 960/2] = 0x46ff465e;
            vram2[i + i * 960/2] = 0x6d216d4b;
        }
    }

gives this - link to the image