Porting a camera sx530hs

reyalp

14080

Re: Porting a camera sx530hs

« Reply #260 on: 01 / July / 2017, 01:43:08 »

Advertisements

Quote from: axman on 30 / June / 2017, 14:54:02

Re: concerns about filewrite 'skip-dir' and 'skip-flush' code sections.. I believe I can now insert logging statements and compile with success.

This is really more of a reverse engineering problem, so I won't be able to give you a cookbook answer.

If I were working on this port, I'd start by trying to figure out what the code related to sub_FF02D9F0 / R7 does, and how this section of this ports filewrite differs from earlier cameras like elph130 (which has an otherwise similar filewrite)

I'd also look at the value from "LDR R1, [R5, #0x14]"

R5 is a global structure at 0x107A8, so + 0x14 = 0x107BC.

The following BLX R1 indicates it's a callback of some sort (the BNE skips the call if it's null), and the first parameter depends on the R7 value. elph130 has similar callback code, it just doesn't have a parameter that depends on the result of the skipped call.

Some questions are:
1) Is callback actually used in normal operation, or is it some Canon development hook that's always 0? If it's always zero, then the rest probably doesn't matter.
2) If it is used, does it need to be called or skipped when writes are skipped? (elph130 would call regardless)
3) Is it the same callback every time?
4) How does the behavior depend on the value controlled by R7

So my first step would probably be logging the value of r7 and *(int *)(0x107BC) while shooting without remote shoot, with and without continuous, with and without a directory needing to be created etc.

Looking at the code a bit more, I think the location of loc_A is incorrect. The code that handles the directory creation (starting at loc_FF3AF300) ends by either jumping to loc_FF3AF220 (the start of the main loop) or loc_FF3AF40C. This depends on the callback in 0x107BC mentioned above.

So to get similar behavior to earlier ports, I would put loc_A before that branch, like

Code: [Select]

//mod start
"    LDR R3, =ignore_current_write\n" // !!
"    LDR R3, [R3]\n"
"    CMP R3, #0\n"
"    BNE loc_A\n" // skip creating directory
//mod end
"    BL      sub_FF027628 \n"
"    MOV     R1, #0 \n"
"    MOV     R0, #0x48 \n"
"    BL      sub_FF0CA2F0 \n"
"    ADD     R0, R4, #0x58 \n"
"    BL      sub_FF030DA4 \n"
"    LDR     R1, [R5, #0x1C] \n"
"    BL      sub_FF02EC74 \n"
"loc_A:\n"
"    LDR     R1, [R5, #0x14] \n"
"    CMP     R1, #0 \n"
"    BEQ     loc_FF3AF220 \n"
"    LDR     R0, [R4, #0x10] \n"
"    B       loc_FF3AF40C \n"

This separates the directory case from the confusion with R7

Note that the R0 parameter for the callback in that case comes from R4+0x10, which is inside the message structure for that particular filewrite invocation.

Logged

Don't forget what the H stands for.

axman

145

Re: Porting a camera sx530hs

« Reply #261 on: 01 / July / 2017, 12:49:15 »

Thanks for the feedback. I will move loc_A as you suggest, no other change, then test.

At this moment, going deeper is beyond my current ability. Furiously studying. Your post is and will be used as reference for thinking about how the code works, and what to pay attention to.

So. I appreciate the time you spend to help me and others learn. I will return to this investigation when I'm capable of carrying it out without significant hand holding. Meanwhile, if any testing or experiments are useful, I can do that at any time. Thanks again.

Logged

axman

145

Re: Porting a camera sx530hs

« Reply #262 on: 09 / July / 2017, 19:53:44 »

loc_A is moved to the spot @reyalp suggested above.

Code for logging debug msgs is added. filewrite.c attached for ref. It compiles and runs chdk on the camera, and it mostly logs debugging stuff when called.

Hoping for feedback on how I implemented the calls to debug-logging.

I can provide copious details on the test results. But if I am doing the logging wrong, there is no point to uploading those test logs..

Note up front that I do not have calls to debug-log everywhere I'd like. Seems as though the call to debug-log can only be in one place, or the camera crashes..

With the call to debug-logging in its current location, the camera runs almost all the tests without error, and logs some debug info as well..

Any guidance is appreciated, thanks in advance.

filewrite.c (14.37 kB - downloaded 21 times.)

Logged

reyalp

14080

Re: Porting a camera sx530hs

« Reply #263 on: 09 / July / 2017, 21:32:10 »

Quote from: axman on 09 / July / 2017, 19:53:44

Note up front that I do not have calls to debug-log everywhere I'd like. Seems as though the call to debug-log can only be in one place, or the camera crashes..

Safely adding logging requires a good understanding of the surrounding assembly and arm calling convention, and preserve any registers as needed.

In general:
calling a function can trash R0-R3, LR, R12, and the condition code. So for example, if the code before your log call puts something in R0, and code afterwards uses R0, it will be broken. R0-R3 are also the first 4 arguments of a function call. So if you put your call right before a function cal that takes arguments, it will be broken. You can look at the called function to understand if it takes arguments. Function return values are in R0.

If your function doesn't need any of existing register values, surrounding the call with ASM_SAFE should preserve everything, like

Code: [Select]

#include "asmsafe.h"
...
    asm volatile (
"....  asm code..."
ASM_SAFE(
"bl my_log\n"
)
".... more asm code..."

If you need to pass something to your logging call, it gets a little more complicated.

Quote

With the call to debug-logging in its current location, the camera runs almost all the tests without error, and logs some debug info as well..

Almost?

I'm not clear where the where the "RSEVEN" value 0x107C0. The value in question is the return value of sub_FF02D9F0. You could log this using something like

Code: [Select]

void log_r7(int val) {
 _LogCameraEvent(0x60,"fw r7 %08x",val);
}
...
"    BL      sub_FF02D9F0 \n"
"loc_B:\n"
"    MOV     R7, R0 \n"
"bl log_r7\n"
"    ADD     R0, R4, #0x58 \n"

At the location log_r7 is added, R0 (which is the first argument to a function in arm) already contains the value we are interested in, and the value has already been saved in r7. The very next instruction puts a totally different value in R0, so we don't need to preserve it. Since no other register values are set between the call to sub_FF02D9F0 and our code, we don't have to worry about preserving R1-R3 etc (ignoring case where execution got there via loc_B, since that's suspect no matter what.)

For the other value, you can just log *(int *)(0x107BC) like

Code: [Select]

 _LogCameraEvent(0x60,"fw *0x107BC %08x",*(int *)(0x107BC));

This value should either be 0 (meaning the whole calback code path isn't used) or a pointer to ROM code. I would log it directly after the call to sub_FF02EC74 below loc_B

I'll try to look at one of my cameras to see what the behavior of the equivalent to the 0x107BC callback is.

edit:
Another thing to watch out for when using _LogCameraEvent is that total string length must be pretty short (<64-ish characters) or you will get an assert in _LogCameraEvent itself.

« Last Edit: 10 / July / 2017, 00:24:56 by reyalp »

Logged

Don't forget what the H stands for.

reyalp

14080

Re: Porting a camera sx530hs

« Reply #264 on: 10 / July / 2017, 00:45:52 »

On elph130, the callback is called in normal operation. It releases some semaphores and does various other stuff. I'd expect sx530 does as well.

I've attached the code I used as an example. Here's a snippet of the log

Code: [Select]

00035970: UI:fw A/CacheFlush
00035970: UI:fw u 00000000 09200000 00000000 00000000 00000000 001a5310
00036000: UI:ScreenLock
00036000: UI:ScreenUnLock
00036000: UI:fw cb:0xff1d77ec 153092096

The second number is the parameter passed to the callback function (=0x9200000 in this case), which is probably related to the values controlled by R7 on sx530

ixus140_elph130-filewrite-dbg-reyalp-1.patch (1.7 kB - downloaded 23 times.)

Logged

Don't forget what the H stands for.

axman

145

Re: Porting a camera sx530hs

« Reply #265 on: 10 / July / 2017, 15:20:21 »

Quote from: reyalp on 09 / July / 2017, 21:32:10

Almost?

43 test runs so far. Two tests errored and failed.

One was a bogus error, my fault. I exceeded chdku timeout with ShortExp value that was too long (10s). I believe this one can be disregarded.

Second error was with camera in CREATIVE shooting mode. chdkptp 'shoot' fails to produce an image; I believe CREATIVE shooting mode is unsupported. But I tested with every mode anyway, to see if any effects on logging output.

I think SCN mode fails in same way as CREATIVE. M, LIVE, AUTO, AUTO-Hybrid, FISHEYE, and MOVIE modes were ok - no crashes. Sometimes no image, sometimes no logging, but no crashes. I did not test Tv, Av shooting modes yet.

Quote from: reyalp on 10 / July / 2017, 00:45:52

On elph130, the callback is called in normal operation. It releases some semaphores and does various other stuff. I'd expect sx530 does as well.

I've attached the code I used as an example. Here's a snippet of the log

Code: [Select]
00035970: UI:fw A/CacheFlush 00035970: UI:fw u 00000000 09200000 00000000 00000000 00000000 001a5310 00036000: UI:ScreenLock 00036000: UI:ScreenUnLock 00036000: UI:fw cb:0xff1d77ec 153092096The second number is the parameter passed to the callback function (=0x9200000 in this case), which is probably related to the values controlled by R7 on sx530

Thank you, kind Sir!

I will learn by improving the placement of debug logging as suggested above.
Then to re-testing.
It will take time to get my head around the details - and and and -

THANKS VERY MUCH for the explanation and guidance! :-D

Logged

reyalp

14080

Re: Porting a camera sx530hs

« Reply #266 on: 10 / July / 2017, 16:20:34 »

Quote from: axman on 10 / July / 2017, 15:20:21

43 test runs so far. Two tests errored and failed.

I think SCN mode fails in same way as CREATIVE. M, LIVE, AUTO, AUTO-Hybrid, FISHEYE, and MOVIE modes were ok - no crashes. Sometimes no image, sometimes no logging, but no crashes. I did not test Tv, Av shooting modes yet.

It's quite possible that scripted shoot doesn't work in some modes if the raw hook isn't reached. DNG is also likely to have problems in some of these modes.

I wouldn't try to exhaustively test every mode for the filewrite stuff though. For that, the focus should be on answering specific questions, like the ones I listed in https://chdk.setepontos.com/index.php?topic=12418.msg133693#msg133693

#1 is almost certainly yes, based on the elph130 result.
#2 is yes for existing working ports, since they call the callback even in the case file writing is skipped.
#3 is unknown, but I'd probably ignore it for now.
#4 is unknown, but from elph130 it looks complicated enough that there isn't an obvious value to use in the case where file writing is skipped

New questions:
Following on #2, is what happens if the callback is skipped when the write is skipped? If it turns out to be OK, this is an easy solution.

If it's not OK, then we need to understand then we have to figure out what value to use for the R7 value. Observing this might provide a simple solution anyway.

Logged

Don't forget what the H stands for.

axman

145

Re: Porting a camera sx530hs

« Reply #267 on: 13 / July / 2017, 15:05:00 »

Quote from: reyalp on 10 / July / 2017, 16:20:34

#1 is almost certainly yes, based on the elph130 result.
#2 is yes for existing working ports, since they call the callback even in the case file writing is skipped.
#3 is unknown, but I'd probably ignore it for now.
#4 is unknown, but from elph130 it looks complicated enough that there isn't an obvious value to use in the case where file writing is skipped

New questions:
Following on #2, is what happens if the callback is skipped when the write is skipped? If it turns out to be OK, this is an easy solution.

If it's not OK, then we need to understand then we have to figure out what value to use for the R7 value. Observing this might provide a simple solution anyway.

Special attention paid to these ^.

1) seems the contents of 0x107bc are always FF1EFD1C with arg : 1
2) "they call the callback even when file writing is skipped"
I've had a hard time grasping this.
The func related to 0x107bc is called every time that I can see.
Every test logged data via the calls to debug-log except one; chdkptp shoot
3) Value seems to be the same every time, if I have done the logging right: ff1efcbc arg : 0
4) I am not sure I captured R7 correctly.

NewQ) If I understand what 'skip the write' means,

All tests that make use of chdk filewritetask seem to behave ok. They do not crash, they put jpg and dng files where commanded. Debug logging output is realized for all these normal cases. Only when I misconfigure the cam or chdk did I get abnormal results.

Current filewrite.c attached. Spreadsheet with test results and notes available, as well as all dbg.logs.

Feedback is most welcome - understanding this, coding stuff for it, and keeping track of what's what is kicking my posterior.

filewrite.c (14.17 kB - downloaded 19 times.)

Logged

reyalp

14080

Re: Porting a camera sx530hs

« Reply #268 on: 13 / July / 2017, 21:48:31 »

Quote from: axman on 13 / July / 2017, 15:05:00

4) I am not sure I captured R7 correctly.

log_fwt_mid would log the value which goes into R7 as arg2.

To be clear, you should be testing this with normal shooting, not remoteshoot.

I don't understand the intent of the other logging calls.

Quote

NewQ) If I understand what 'skip the write' means,

When you use remote shoot, the filewrite modifications skip the part that would otherwise write to the SD card. This is when ignore_current_write is set.

Quote

All tests that make use of chdk filewritetask seem to behave ok.

The problem is, when ignore_current_write is set the value that ends up in R7 is undefined, because the function call that would have set it is skipped. It's some totally unknown, random value from earlier in the code, unrelated to whatever logic the firmware expects to do with that value. So the fact that it happens to not crash is not sufficient.

You need to ensure that a known OK value is set when ignore_current_write is used, something like

Code: [Select]

"						LDR R3, =ignore_current_write\n" // mod start
"						LDR R3, [R3]\n"
"						CMP R3, #0\n"
"						MOVNE R0,#1\n //fake return value of skipped sub_FF02D9F0 call
"						BNE loc_B\n" // skip flushing the cache

But it's unknown whether just setting the value to 1 is OK or not.

The code that uses the value only checks whether it's equal to 1 or not. Maybe either case is OK, but we should use specific value.

Logged

Don't forget what the H stands for.

axman

145

Re: Porting a camera sx530hs

« Reply #269 on: 17 / July / 2017, 01:08:35 »

Quote from: reyalp on 13 / July / 2017, 21:48:31

You need to ensure that a known OK value is set when ignore_current_write is used, something like

Code: [Select]
" LDR R3, =ignore_current_write\n" // mod start " LDR R3, [R3]\n" " CMP R3, #0\n" " MOVNE R0,#1\n //fake return value of skipped sub_FF02D9F0 call " BNE loc_B\n" // skip flushing the cacheBut it's unknown whether just setting the value to 1 is OK or not.

The code that uses the value only checks whether it's equal to 1 or not. Maybe either case is OK, but we should use specific value.

Did ^ this. chdkptp shoot = 1x jpg saved to sdcard good.

fwt log; 00039160: UI:fw mid:ff1efd1c arg2:1

Filewrite appears to return the faked value when bypassing saving to sdcard. I can test several chdk overrides with the shoot cmd, if useful.

Logged