You can log code sequences from other branches as well. Here's an example for debugging
compressed_raw on 5D3 1.2.3:
Makefile.user:
CONFIG_DEBUG_INTERCEPT = y
Merge the two branches:
hg update compressed_raw -C
hg merge dm-spy-experiments
(there will be some merge conflicts, sorry about that, I'm still novice in this area)
(maybe it's best to cleanup the dm-spy-experiments branch a bit and merge it in mainline)
(ignore mlv_lite and mlv_rec for now, as we are not going to use them - just merge the other files)
Change the code to enable logging:
diff -r ad3969261ccf modules/silent/lossless.c
--- a/modules/silent/lossless.c
+++ b/modules/silent/lossless.c
@@ -3,6 +3,7 @@
#include "lens.h"
#include "raw.h"
#include "edmac.h"
+#include "dm-spy.h"
struct TwoInTwoOutLosslessPath_args
{
@@ -251,10 +252,18 @@
int lossless_compress_raw(struct raw_info * raw_info, struct memSuite * output_memsuite)
{
- return lossless_compress_raw_rectangle(
+ /* start logging */
+ debug_intercept();
+
+ int result = lossless_compress_raw_rectangle(
output_memsuite, raw_info->buffer,
raw_info->width, 0, 0,
raw_info->width, raw_info->height
);
+
+ /* stop logging and save to file */
+ debug_intercept();
+
+ return result;
}
Now compile ML core and the silent picture module, place them on the card, and take a full-res silent picture with lossless compression (so the routine we have modified will get called in a quiet context - with LiveView turned off).
cd platform/5D3.123
make clean; make
make installq # this copies only autoexec and sym file
cd ../../modules/silent
make clean; make
make install # copy only this module to your card
You should get a file named dm-000.log in the root of the card, that contains these lines (among many others):
172EB> shoot_task:000aeef0:00:00: *** register_interrupt("Jp57IntrHandler", 0xa3, 0xff291e2c, 0x0), from ff3dcc78
17882> shoot_task:ff3dd01c:16:03: [TTL] START WR1:0x18800064 WR2:0x15a0c000
178B2> shoot_task:ff3dd048:16:03: [TTL] START RD1:0x86051a8 RD2:0xad24490
34733> **INT-A3h*:ff3dcc08:16:03: [TTL][0,0,0] JpCoreCompleteCBR( 0x15336af )
3476D> **INT-83h*:00a0e980:00:00: LosslessCompleteCBR
Want more details?Let's enable interrupts and ENGIO messages:
diff -r 9146aa47814c src/dm-spy-extra.c
--- a/src/dm-spy-extra.c
+++ b/src/dm-spy-extra.c
@@ -20,7 +20,7 @@
#include "timer.h"
/* this needs pre_isr_hook/post_isr_hook stubs */
-//~ #define LOG_INTERRUPTS
+#define LOG_INTERRUPTS
/* delay mpu_send calls, to allow grouping MPU messages by timestamps */
#define MPU_DELAY_SEND
@@ -338,11 +338,11 @@
{ 0xff2953b8, "LockEngineResources", 1, LockEngineResources_log },
{ 0xff29555c, "UnLockEngineResources", 1, UnLockEngineResources_log},
- //~ { 0xff290f98, "engio_write", 1, engio_write_log}, /* on 5D3, Canon's engio_write is silent */
- //~ { 0xff290c80, "EngDrvOut", 2 }, /* same here */
- //~ { 0xff290ca0, "EngDrvIn", 1 },
- //~ { 0xff290d38, "EngDrvBits", 3, engdrvbits_log},
- //~ { 0xff290cd4, "EngDrvIns", 3 },
+ { 0xff290f98, "engio_write", 1, engio_write_log}, /* on 5D3, Canon's engio_write is silent */
+ { 0xff290c80, "EngDrvOut", 2 }, /* same here */
+ { 0xff290ca0, "EngDrvIn", 1 },
+ { 0xff290d38, "EngDrvBits", 3, engdrvbits_log},
+ { 0xff290cd4, "EngDrvIns", 3 },
/* only EngDrvOuts is verbose, no need to log it here */
//~ { 0xFF694880, "eeko_setup_global_vars", 10 },
diff -r 9146aa47814c src/dm-spy.c
--- a/src/dm-spy.c
+++ b/src/dm-spy.c
@@ -52,8 +52,6 @@
{
if (!buf) return;
- if (class == 21) // engio, lots of messages
- return;
#ifdef CONFIG_7D
if (class == 0x3E) // IPC, causes ERR70
Lots of messages now! Let's look at some of them.
How does SetEDmac work?CDD68> shoot_task:000af06c:00:00: *** SetEDmac(0x11, 0x58800064, 0x1c42ac, 0x20000001), from ff580f28
CDD80> shoot_task:000af168:00:00: *0x1c42ac = { 0 0 0 0 0 0 2000 0 fff 0 0 a0f7f8 ... }
CDDBD> shoot_task:ff290e18:15:02: [ENGIO](Addr:0xc0f2610c, Data:0x 0)[8]EngDrvOuts
CDDE5> shoot_task:ff290e18:15:02: [ENGIO](Addr:0xc0f26110, Data:0x fff2000)[7]EngDrvOuts
CDE0F> shoot_task:ff290e18:15:02: [ENGIO](Addr:0xc0f26114, Data:0x 0)[6]EngDrvOuts
CDE32> shoot_task:ff290e18:15:02: [ENGIO](Addr:0xc0f26118, Data:0x 0)[5]EngDrvOuts
CDE55> shoot_task:ff290e18:15:02: [ENGIO](Addr:0xc0f2611c, Data:0x 0)[4]EngDrvOuts
CDE79> shoot_task:ff290e18:15:02: [ENGIO](Addr:0xc0f26120, Data:0x 0)[3]EngDrvOuts
CDE9C> shoot_task:ff290e18:15:02: [ENGIO](Addr:0xc0f26124, Data:0x 0)[2]EngDrvOuts
CDEBF> shoot_task:ff290e18:15:02: [ENGIO](Addr:0xc0f26128, Data:0x 0)[1]EngDrvOuts
CDEE5> shoot_task:000125c0:15:01: ResetEDmac(0x20000001)
CDF1F> shoot_task:000af06c:00:00: *** EngDrvOut(0xc0f26104, 0x20000001), from 125d4
CDF55> shoot_task:000af06c:00:00: *** EngDrvOut(0xc0f26108, 0x18800064), from 125ec
This reveals the register configuration performed by SetEDmac.
How do we know where to stop? The next line reads:
CDF9C> shoot_task:000af06c:00:00: *** RegisterEDmacCompleteCBR(0x11, 0xff580b3c "[PackMem] CompleteInterrupt In %d", 0x11), from ff580f38
which is the next call, and nothing interesting happens in-between (so, all those messages must be from SetEDmac).
Alternative: log the return value of SetEDmac, so you'll know for sure where this call ends. Exercise for the reader.
How does the main CPU know when the compression is finished?The JPCORE CPU announces it using an interrupt:
EC9F6> **INT-A3h*:000aed4c:00:00: >>> INT-A3h Jp57IntrHandler ff291e2c(0)
ECA36> **INT-A3h*:000af06c:00:00: *** EngDrvIn(0xc0e20044), from ff291ce4
ECA70> **INT-A3h*:000af06c:00:00: *** EngDrvIn(0xc0e20024), from ff291d18
ECA90> **INT-A3h*:ff3dcc08:16:03: [TTL][0,0,0] JpCoreCompleteCBR( 0x1403b4e )
ECADC> **INT-A3h*:000af06c:00:00: *** EngDrvOut(0xc0f26104, 0x20000006), from 12aec
...
ECCB1> **INT-83h*:00000588:00:00: <<< INT-A3h done
That magic number is 0x1403b4e = 20986702 - looks like a valid compressed size for a full-res picture (and you can confirm by printing output_size in lossless.c).
OK, so that must be where the firmware finds out the compressed size! Let's see which of these registers returns it. Enable logging the return value of EngDrvIn and repeat the experiment:
- { 0xff290ca0, "EngDrvIn", 1 },
+ { 0xff290ca0, "EngDrvIn", 1 | RET },
D46DC> **INT-A3h*:000aed4c:00:00: >>> INT-A3h Jp57IntrHandler ff291e2c(0)
D4720> **INT-A3h*:000af06c:00:00: *** EngDrvIn(0xc0e20044), from ff291ce4
D482B> **INT-A3h*:000af1d0:00:00: !!! cannot log return value (err 10)
D4876> **INT-A3h*:000af06c:00:00: *** EngDrvIn(0xc0e20024), from ff291d18
D491E> **INT-A3h*:000aee24:00:00: ==> 0x14264a0, from ff291d18
D4954> **INT-A3h*:ff3dcc08:16:03: [TTL][0,0,0] JpCoreCompleteCBR( 0x14264a0 )
D49AA> **INT-A3h*:000af06c:00:00: *** EngDrvOut(0xc0f26104, 0x20000006), from 12aec
...
D4E17> **INT-0Ah*:00000588:00:00: <<< INT-A3h done
So it's the register 0xc0e20024 where compressed output size is coming from!
Still, what's up with 0xc0e20044? Why its value could not be logged? Look up the error code in patch.h => E_PATCH_CACHE_COLLISION...
Oh no, a cache conflict! What do we do?Check the index bits of ff291ce8 (LR after the first EngDrvIn call): 0xff291ce8 & 0x7E0 = 0x4e0. Check the other logged addresses (I know, this should be automatic) => 0xff4fa4ec & 0x7E0 = 0x4e0. Comment it out.
Not feeling like doing the math? Just comment out all other ROM addresses (those starting with FF).
E45AF> **INT-A3h*:000aed4c:00:00: >>> INT-A3h Jp57IntrHandler ff291e2c(0)
E45F3> **INT-A3h*:000af06c:00:00: *** EngDrvIn(0xc0e20044), from ff291ce4
E4681> **INT-A3h*:000aee24:00:00: ==> 0x400, from ff291ce4
E46D2> **INT-A3h*:000af06c:00:00: *** EngDrvIn(0xc0e20024), from ff291d18
E47C4> **INT-A3h*:000aee24:00:00: ==> 0x14c14d8, from ff291d18
E47FA> **INT-A3h*:ff3dcc08:16:03: [TTL][0,0,0] JpCoreCompleteCBR( 0x14c14d8 )
With this method and some patience, you can trace just about anything in the firmware.