Debugging

Intruduction

This page collects tools and techniques for debugging CHDK code

LEDs

A simple way to see if a particular code path is reached.

In a complete CHDK port the started() and finished() macros turn on and off the CHDK debug LED . The debug LED is normally the blue direct print LED. On cameras that do not have a direct print LED, a different one will be used. The AF led should NOT be set as the debug LED in any build intended for normal use, because it would interfere with taking pictures.

Using LEDs directly

First, you need to know an LED MMIO address.

TODO link some led finder code.

The LED is turned on by writing 0x46 to the address, and turned off by writing 0x44

C

From C, you can do something like this to blink an LED cnt times. The nops are used to create a delay. The length of the delay will depend on the camera and whether caches are currently enabled, but should be sufficient to see the led blinking.

#define LED_PR 0xc0220134 // your LED address
...
	volatile int *p=(void*)LED_PR;
	for(;cnt>0;cnt--){
		*p=0x46;

		for(i=0;i<0x200000;i++){
			asm ("nop\n");
			asm ("nop\n");
		}
		*p=0x44;
		for(i=0;i<0x200000;i++){
			asm ("nop\n");
			asm ("nop\n");
		}
	}

Some things to watch out for

• If you call this code from inline assembler, you need to make sure to preserve any registers. The ASM_SAFE macro may be used for this purpose.
• In some parts of the code, the stack may not be properly set up, in which case any variables should be static or global.
• If you want to put this code in an __attribute__((naked)) function, you should also avoid using local variables. In general you should not put any C code in these functions.
• In some parts of the code - especially early in the booting process - the use of delay loops to actually blink the camera LED can potentially disrupt the boot timing. It is safer to simply turn on the LED rather than blink it.

        #define LED_PR 0xc0220134 // your LED address
 	volatile int *p=(void*)LED_PR;

..

Assembler

You might want to blink an LED directly from assembler code

// for testing, blink LED at 0xC0220130 10 times
	LDR     R3, =0xC0220130
	MOV		R1,#10
2:
	MOV     R2, #0x46
	STR     R2, [R3]
	MOV     R0, #0x8000
1:
	SUB R0,R0,#1
	CMP R0,#0
	BNE 1b
	MOV     R2, #0x44
	STR     R2, [R3]
	MOV     R0, #0x8000
1:
	SUB R0,R0,#1
	CMP R0,#0
	BNE 1b

	SUB R1,R1,#1
	CMP R1,#0
	BNE 2b

Using LEDs from Canon Basic/Eventprocs

The LEDs can also be controlled using the LEDDrive function, either from Canon Basic or as an Event Procedure.

Camera crash logs (romlog)

When the canon firmware crashes, it will normally write the current registers, a stack dump, and the recent entries from the camera log to internal flash memory and then shut down. This is generally referred to as the romlog.

Reading the romlog

As of changeset 1432, the romlog can be saved from the CHDK menu, using "miscellaneous stuff->Debug Parameters->Save ROM crash log"

The romlog can also be saved to to a file using Canon_Basic/Scripts/Romlog or Lua/Scripts:Standard/Test/Romlog

Notes

• Some older vxworks cameras will automatically shut down after saving the log. This is normal.
• If the camera has never crashed, the romlog function will fail.

Interpreting the romlog

Text below refers the the plain text romlogs produced by DryOS and some later vxworks cameras. Older vxworks cameras output the romlog in a binary format, some information is available in this forum thread http://chdk.setepontos.com/index.php?topic=5394.0

The first line of the romlog describes the kind of error that occurred. Known errors include ASSERT, EXCEPTION, WATCHDOG and HARDWARE DEFECT. ASSERT and EXCEPTION are most commonly encountered in CHDK development. The remainder of the log varies slightly depending on the error.

Example assert

ASSERT!! FsIoNotify.c Line 451
Occured Time  2010:06:26 18:10:53
Task ID: 1441797
Task name: SpyTask
SP: 0x002FCE44
StackDump:
0x00000000
0x00000008
0xFF8187F8
...

The stack dump can help you figure out which functions were called an in some cases what their parameters were. Rather than actually working through all the calls, it is frequently sufficient to just look for addresses that look like code, either ROM or within CHDK address space. Keep in mind that the final entry in the stack dump is the call to assert itself.

Example exception

Exception!! Vector 0x10
Occured Time  2010:05:30 13:05:27
Task ID: 1441797
Task name: SpyTask
Exc Registers:
0x0000007A
0x00008000
0x00000050
0x65784500
0x00000006
0x00000000
0x00000005
0x00000014
0x19980218
0x19980218
0x19980218
0x19980218
0x80000000
0x002FCEC0
0x0014C427
0x0014C43E
0x00000033
StackDump:
0xFF812398
0x00002E10
0x00000010
...

Unlike assert, the exception log includes the CPU registers at the time the exception occurred. The 15th register is LR, 16th register is the instruction pointer (PC), and the 17th is the program status word.

Keep in mind the LR will point to the instruction after the BL instruction, and may have lowest bit set if the call was from thumb code. PC will not have the low bit set in thumb code.

The exception vector tells you what kind of exception occurred. Descriptions of the exception handling process can be be found in the ARM9E-S Core Technical Reference Manual.

Example DryOS Panic

System Panic: Module = 64, Panic = 4
Occured Time  2011:04:03 13:46:30
StackDump(0x2FCED0 - 0x2FCF50):
0x002FCED0
0x0028CAB8
0x00000000
0xFF81C2E0
0x00000000
0x00000001
...

Not clear what the Module and Panic numbers mean.

Example hardware defect

HARDWARE DEFECT!!  ShutdownReason[9] ErrorNo[41]
Occured Time  2011:12:11 21:02:23
00000550: UI:PB.CreateE
00000560: UI:DisplayPhysicalScreenCBR
00000560: UI:AC:StartPB
00000560: UI:DispSwCon_TurnOnDisplayDevice
00000560: UI:AC:EBtn
00000560: UI:PB.Start

Note the above appears to be triggered by CHDK in this case, not an actual hardware defect. thread

Common Exception Vectors

In CHKD debugging, the most commonly encountered exception is 0x10 Data abort. This occurs when the code attempts to access an invalid memory address. 0x4 Undefined Instruction is also is also common, caused by bad code pointers or stack corruption.

Exception	Vector address	Description
Reset	0x00000000
Undefined instruction	0x00000004
SWI	0x00000008
Prefetch Abort	0x0000000C
Data Abort	0x00000010	Happens on access to invalid memory address
Reserved	0x00000014
IRQ	0x00000018
FIQ	0x0000001C

Source: ARM9E-S Core Technical Reference Manual

Locating CHDK code from romlog addresses

The CHDK build process writes disassembly dumps of the main CHDK binary. The dump for the main code is stored in core/main.dump

The dump for the loader code (which includes the main code, but not located at the final address) is stored in loader/<camera>/main.dump

You can search these dumps for addresses that appear in the romlog, which will help you find the corresponding C source. Note that Thumb addresses may appear in the stack dump or registers with the lowest bit set.

Note: The CHDK-Shell tool may automatically delete these files after building by default. Disable "Compile Options > Skip GMAKE clean AFTER compilation" to keep them. [Note from author: CHDK-Shell will also save dumps to /bin/logs/dump-{cameraname}-{firmware}.txt by default. This is controlled by the checkbox named "ELF objdump", just above the "Compile Selected" button ]

Memory values

There are two common ways to inspect memory values in CHDK

Misc debug values

This displays four memory values in the CHDK OSD. The display can be turned on or of in the CHDK menu under miscellaneous stuff->Debug parameters->Show misc. values

By default, the values listed below are shown, but this can be be changed in core/gui.c gui_draw_debug_vals_osd()

u: usb power state
1: the address selected in the memory browser (see below)
f: the focus_busy value
z: the zoom_busy value

Early in the porting process, you may want to hard code this to always be displayed, and also uncomment the first call to gui_draw_debug_vals_osd() in gui_draw_osd to ensure it is drawn even if some variables are wrong.

Memory browser

This allows you to interactively view memory addresses. The right/left buttons increment/decrement the address, and the zoom in/zoom out controls the increment size. On cameras without zoom button or zoom lever, the Disp button can be used to change the increment size.

Note that if you attempt to browse an invalid memory location (or the selected memory location holds an invalid address), the camera will shut down with an exception.

By default, the value of the selected address is also shown in misc debug values, so you can use this to set a "watch" without changing code.

There is a modified version of this debug tool which adds some functionality, here: http://chdk.setepontos.com/index.php?topic=6635.0

Logging camera console output

Many firmware functions output information to the cameras console. Normally, this is discarded, but it it can be recorded with the following methods.

Some functions that put useful information to the camera console

• ShowCameraLog outputs recent entries in the cameras log. (to be described more below!)
• Printf can be used to send arbitrary text to the camera console (UART).
• LogPrintf (not an event proc, need to find the address) can send output to the camera log. LogPrintf takes a number as the first argument, followed by a format string and a variable number of additional arguments. The number specifies a prefix that appears on the log message, either SS: or UI:, and may also have other functions. 0x120 is generally used for SS. The camera log does not appear in the camera standard output by default, but recent entries can be sent there using the ShowCameraLog event proc. Recent log entries will also appear in ROMLOGs.

UART redirection (DryOS)

DryOS (TODO and possibly late vxworks ?) cameras can redirect UART console output with StartRedirectUART Event Procedure. To use this function, a file named uartr.req must be present in the root of the SD card, and must start with the bytes 0x77 0x21 0xce 0x82 .

StartRedirectUART(int buffer_size,const char *filename)

buffer_size controls how much output is buffered. The value is rounded up to 8192 bytes.

filename is the name of the file to write. If NULL, an name will be automatically picked based on tick count. If a name is given, output will be appended to the file.

The standard CHDK distribution includes the uartr.lua lua module which provides an interface to this.

Note that a sleep() appears to be required between enabling uart redirection and the first output being recorded.

UART redirection may be stopped with StopRedirectUART() .

UART Console

UART Console allow access to Canon Event Shell and DryOs Shell (drysh).

UART pinout on Camera PCB have to be discovered for your Camera. Look SD4000 for example.

VxWorks

Many VxWorks cameras support the CAM_CONSOLE_LOG_ENABLED #define in camera.h. When this is enabled, camera STDOUT will be sent to A/stdout.txt

Note, this may cause instability, probably because it uses standard IO functions within a device driver.

Example

The following example shows using the PTP Extension with the chdkptp client to get console output

con 1> =require('uartr').start('A/TEST.LOG')
con 2> =call_event_proc('ExMem')
con 3> =call_event_proc('ExMem.View')
con 4> =call_event_proc('ShowCameraLog')
con 5> d test.log
A/test.log->test.log

The commands above

1. start uart redirection, appending to TEST.LOG
2. register the "ExMem" group of eventprocs
3. Call ExMem.View, which prints ExMem information to test.log
4. Call ShowCameraLog, which prints recent camera log entries to test.log
5. downloads test.log