SD info and benchmarks (was Re: EOS M3 porting)

Good work. Can you share some details about how you did it?

It seems that we should not rely on reyalp's logs. So I've analyzed ACMD41 responces from logs given from some Digic5 DSLRs and from QEMU. DSLRs' logs contain more SD related messages. I've patched some functions to generate debug messages on M3:
00320: InitFileModules:0x010f0007: [CMD55, 0x00000000]
00320: CommonDrivers:0x010f192d: [Read, 0x00000001]
00320: InitFileModules:0x010eff7f: [CMD41, 0x51100000]
00320: CommonDrivers:0x010f192d: [Read, 0x00000001]
00320: InitFileModules:0x003a8b3b: [Read, 0xff8000ff]
00320: InitFileModules:0x003a8b47: [Read, 0x204f3f41]
00320: InitFileModules:0x010effad: [Resp, 0x204f3f41.ff8000ff]
00320: InitFileModules:0x010f0007: [CMD55, 0x00000000]
00330: PhySw:0x010f192d: [Read, 0x00000001]
00330: InitFileModules:0x010eff7f: [CMD41, 0x51100000]
00330: CommonDrivers:0x010f192d: [Read, 0x00000001]
00330: InitFileModules:0x003a8b3b: [Read, 0xff8000ff]
00330: InitFileModules:0x003a8b47: [Read, 0x20833f41]
00330: InitFileModules:0x010effad: [Resp, 0x20833f41.ff8000ff]
00350: InitFileModules:0x010f0007: [CMD55, 0x00000000]
00350: DefMarkRomCopyTask:0x010f192d: [Read, 0x00000001]
00350: InitFileModules:0x010eff7f: [CMD41, 0x51100000]
00350: DefMarkRomCopyTask:0x010f192d: [Read, 0x00000001]
00350: InitFileModules:0x003a8b3b: [Read, 0xff8000ff]
00350: InitFileModules:0x003a8b47: [Read, 0x20833fc0]
00350: InitFileModules:0x010effad: [Resp, 0x20833fc0.ff8000ff]
00350: InitFileModules:0x010eead7: [CMD11, 0x00000000]
00350: DefMarkRomCopyTask:0x010f192d: [Read, 0x00000002]
00350: InitFileModules:0x010f1605: [Read, 0x00000003]
00350: InitFileModules:0x010eeaff: CMD11_VoltageSwitch(0) sdconWaitInterrupt() NG!

00430: InitFileModules:0x010eeb41: [Read, 0x8000000f]
00430: InitFileModules:0x010ee391: [CMD2, 0x00000000]Afrer this in some cases I just set bit0 in R1(0x20833fc0->0x20833fc1) at the end of function 0x010F1CF2.

The function call in Startup task that we always remove (the diskboot one) also initializes the card, but probably not in its full performance mode (just so it can access the card and load diskboot.bin, if any). Too bad that we can't log how that works the first time (it would require modified firmware).

I was trying to uncomment function fc0637b2 (commenting fc063804) but I've got some errors during SD i/o.

Your finding likely means that it's actually CHDK that slows down the card.

I was trying to measure SD speed using Canon basic script without CHDK but it works slowly (4 MB/s)

Forcing UHS mode is not likely a good solution (not all cards are UHS), we need to find something else. Either resetting the card, or keeping it powered off for some time.

It could increase system startup time.

Code: [Select]

00320: CommonDrivers:0x010f192d: [Read, 0x00000001]

What's 'Read"?

I was trying to uncomment function fc0637b2 (commenting fc063804) but I've got some errors during SD i/o.

What kind of errors (data corruption or just error entries in logs)? I did this experiment earlier on the sx280 and the only side effect I noticed that startup seemed to take a bit longer (and that it did not speed up card access).

I was trying to measure SD speed using Canon basic script without CHDK but it works slowly (4 MB/s)

You could launch a task (via AdditionAgent) and test from there.

Quote

Forcing UHS mode is not likely a good solution (not all cards are UHS), we need to find something else. Either resetting the card, or keeping it powered off for some time.

It could increase system startup time.

Yes, but question is how much. Some early ports do something like that in their loader (or at least, comments indicate that).
We could also switch off power right at CHDK start (boot.c) and restore it before InitFileModules starts.

What's 'Read"?

010F3F08             SD_read_reg                     ; CODE XREF: sddomWaitR1Busy+12p
010F3F08                                             ; sddomWaitR1Busy+40p
010F3F08                                             ; sddomWaitR1Busy+5Ap
010F3F08                                             ; sddomWaitR1Busy+76p ...
010F3F08 1E 4A             LDR     R2, =0x1106C38
010F3F0A A1 F1 60 51       SUB.W   R1, R1, #0x38000000
010F3F0E 52 F8 20 00       LDR.W   R0, [R2,R0,LSL#2]
010F3F12 40 58             LDR     R0, [R0,R1]
010F3F14 70 47             BX      LRFor more information see SDCON registers QEMU sources. AFAIK EOS M10 already can be emulated in QEMU.

Yes, but question is how much. Some early ports do something like that in their loader (or at least, comments indicate that).
We could also switch off power right at CHDK start (boot.c) and restore it before InitFileModules starts.

Another way could be saving/restoring SD info structures after DISKBOOT.BIN start and skiping card initialization...

Overriding S18A bit I've managed to increase my benchmark results:

Nice work

I finally found time to implement the logging code. Attached are logs from the patriot card that shows 1.8v, and wintec-2012 card from my earlier post along with the code I used.

Observations:
* The logs are different I haven't spent enough time digging in the SD stuff to get much out of them.
* The patriot card spams
InitFileModules [CMD19]=00000000
for a long time after initialization
* The patriot card is also the card that has given me occasional SD card errors at startup, and also occasional very slow (slower than a digic 2 camera) PTP uploads. This could be a symptom of an initialization issue, but I haven't used other cards in the camera enough to be sure they aren't affected, and debugging is hard when the SD card isn't working. I'll see if I can get it to happen with the logging code present, and maybe try a different card in the cam for a while.

I realized that to verify cards are being initialized differently under CHDK, we can call the SD card info function from Canon Basic and use UART redirection to get the output.

Attached is a canon basic script. You must set the address at the top, and configure the card for Canon Basic.

Attached log is from the wintec-2012 card, which did not show 1.8v support when running CHDK. There are no other differences in the output.

edit
restarting the card with
con 3> =return call_event_proc('Driver.Create')
4:return:0
con 4> =return call_event_proc('SetSDPwrPort',0)
5:return:0
con 5> =return call_event_proc('SetSDPwrPort',1)
6:return:0
and then getting the SD info results in "1.8V Support" in the output, but benchmark results seem worse: 10 mb/s or less for all 


edit:
sd info script had some bugs in the uart redirection setup, updated

It would be more helpful if you will log the responces from card, like this 00330: InitFileModules:0x010effad: [Resp, 0x20833f41.ff8000ff]
Stupid question: why do we need to  restart main firmware from the beginning instead patching CreateTask function after DISKBOOT.BIN will be loaded?

It would be more helpful if you will log the responces from card, like this

Code: [Select]

00330: InitFileModules:0x010effad: [Resp, 0x20833f41.ff8000ff]

I'm not clear what you are asking for. If you can explain what specifically this is, I'll try to do it, but my free time is limited so I'd rather not spend it guessing.

Stupid question: why do we need to  restart main firmware from the beginning instead patching CreateTask function after DISKBOOT.BIN will be loaded?

The address DISKBOOT.BIN is loaded is on top of the OS data (on digic 6, it's 0x8000, on older cams 0x1900, both right on top of all the kernel stuff), so the running system is totally clobbered once the diskboot is loaded. That's why we do the whole dance with copy and restart, and then modify the heap address in the Canon code to skip the space we copied our binary to.

I'm not clear what you are asking for. If you can explain what specifically this is, I'll try to do it, but my free time is limited so I'd rather not spend it guessing.

This is the response from SD card to some commands. We need CMD41:




Just google for "part1_410.pdf" and you will find how it should work.

The address DISKBOOT.BIN is loaded is on top of the OS data (on digic 6, it's 0x8000, on older cams 0x1900, both right on top of all the kernel stuff), so the running system is totally clobbered once the diskboot is loaded. That's why we do the whole dance with copy and restart, and then modify the heap address in the Canon code to skip the space we copied our binary to.

And Upgrader.bin works the same?

con 4> =return call_event_proc('SetSDPwrPort',0)

I put this in the boot () function before installing the patches.
Now the card returns the correct response:
00370: InitFileModules:0x010eff7f: [CMD41, 0x51100000]
00370: ClockSave:0x010f192d: [Read Reg:0xc8060010=0x00000001]
00370: InitFileModules:0x003a8b53: [Read Reg:0xc8060034=0xff8000ff]
00370: InitFileModules:0x003a8b5f: [Read Reg:0xc8060038=0x20833fc1]
00370: InitFileModules:0x010effad: [Resp, 0x20833fc1.ff8000ff]It takes more ACMD41 cicles, because now the card is reinitialized. Benchmarks are ok.

But I'm not 100% sure about this solution: SD power is switched off but the card still can get power via data lines...

Quote from: reyalp on 28 / April / 2017, 02:08:50

con 4> =return call_event_proc('SetSDPwrPort',0)

I put this in the boot () function before installing the patches.

Tried the same thing on my M10, and that finally gets me UHS speed. Boot time seems same or faster. Note that this is not possible on all cameras: the sx280 version of SetSDPwrPort uses I2C and needs a running OS.
On the sx280, I switched off SD power for 10ms in Startup task (where the disabled diskboot call is). It worked, but card speed remained below 21MB/s. On this camera, startup times increased significantly when I left the SD powered off.

But I'm not sure about this solution: SD power is switched off but the card still can get power via data lines...

Yes, that's a concern, the SD spec specifically mentions that "DAT, CMD, and CLK should be disconnected or driven
to logical 0 by the host" when the card is powered down.
Perhaps there's a more proper version of SD power control somewhere that also drives the above mentioned pins to a low state?