Dear Members,
Here's a new VSOS kernel version 3.33. This kernel version fixes a bug in the loader and adds powerful debugging features to VSOS.
It's happened to all of us, that we're writing a program, then running it, and suddenly the program gets stuck, nothing happens, and you get stuck wondering what has happened and where the code is stuck at. Now there's a driver INTTRACE.DL3, which binds to the power button interrupt. Whenever you press the power button, you will get a Stop trace, which prints out call stacks, complete with program::function names, timer queues and interrupt lists. It often pinpoints exactly what is running and where the code is stuck (unless it's stuck in an interrupt....). You can use the driver by adding line INTTRACE to your CONFIG.TXT.
Here's an example of a Stop trace:
Code: Select all
VSOS SHELL
S:>playfile d:07 - Orinoco Flow.mp3
Playing '07 - Orinoco Flow.mp3'
[00:01] // <----- POWER BUTTON PRESSED NOW ------->
Stop at 37160(0x9128): IROM::rtos2[128]
Task 0x093c, priority 10, in RUNNING, name "DECOD"
State: 4 (TS_WAIT)
Stack: Start 0x0254, size 0x17c, in use 0x7c, max used 0x166 (0x16 free)
Stack Trace: current PC 0x5423, Tasks::main[185]
Next: PC 0x1e44 @ stack 0x02e2, KERNEL::RunLibraryFunction[33]
Next: PC 0x4876 @ stack 0x02dc, IntTrace::IntReguC[28]
Next: PC 0x4040 @ stack 0x02b5, AUODAC::AudioWrite[68]
Next: PC 0x08ca @ stack 0x02ac, KERNEL::vo_fwrite[30]
Next: PC 0x4fce @ stack 0x02a4, AUDIODEC::DefaultCSOutput[228]
Next: PC 0xe383 @ stack 0x028c, IROM::CodMpg[3491]
Next: PC 0xd7d8 @ stack 0x0277, IROM::CodMpg[504]
Next: PC 0x52a8 @ stack 0x0270, DECMP3::CodMpgPlayFramePatch[10]
Next: PC 0x4d57 @ stack 0x0260, AUDIODEC::MyDecodeAudio[25]
Next: PC 0x49e2 @ stack 0x0258, PLAYFILE::PlayerThread[14]
Task 0x093c, priority 10, in waitQueue, name "DECOD"
State: 4 (TS_WAIT)
Stack: Start 0x0254, size 0x17c, in use 0x7c, max used 0x16e (0xe free)
Stack Trace: current PC 0x918f, IROM::rtos2[231]
Next: PC 0x4040 @ stack 0x02b5, AUODAC::AudioWrite[68]
Next: PC 0x08ca @ stack 0x02ac, KERNEL::vo_fwrite[30]
Next: PC 0x4fce @ stack 0x02a4, AUDIODEC::DefaultCSOutput[228]
Next: PC 0xe383 @ stack 0x028c, IROM::CodMpg[3491]
Next: PC 0xd7d8 @ stack 0x0277, IROM::CodMpg[504]
Next: PC 0x52a8 @ stack 0x0270, DECMP3::CodMpgPlayFramePatch[10]
Next: PC 0x4d57 @ stack 0x0260, AUDIODEC::MyDecodeAudio[25]
Next: PC 0x49e2 @ stack 0x0258, PLAYFILE::PlayerThread[14]
Registers:
i0:0x02b6 i1:0x0012 i2:0x353d i3:0x0943
i4:0x02b5 i5:0x0000 i6:0x02c2 i7:0xfc08
a2:0x0000 a1:0x0004 a0:0x8000 b2:0x0000 b1:0x0000 b0:0x0000
c2:0x0000 c1:0x353d c0:0x0080 d2:0x0000 d1:0x0001 d0:0x0020
p1:0x0000 p0:0x0040 ls:0xe337 le:0xe388 lc:0x0006 mr0:0x0210 lr0:0x9184
Task 0x1c01, priority 10, in waitQueue, name "cyclic"
State: 4 (TS_WAIT)
Stack: Start 0x1c10, size 0x100, in use 0x29, max used 0x3a (0xc6 free)
Stack Trace: current PC 0x918f, IROM::rtos2[231]
Next: PC 0x2bab @ stack 0x1c1e, KERNEL::CyclicMainLoop[42]
Next: PC 0x90b5 @ stack 0x1c11, IROM::exit
Registers:
i0:0x1c1f i1:0x0012 i2:0x1b72 i3:0x1c08
i4:0x1c1e i5:0x0000 i6:0x1c2b i7:0xfc08
a2:0x0000 a1:0x0004 a0:0x8000 b2:0x0000 b1:0x0000 b0:0x0000
c2:0x0000 c1:0x0000 c0:0x0063 d2:0x0000 d1:0x0005 d0:0x0004
p1:0x0000 p0:0x0000 ls:0xebab le:0xffff lc:0x0000 mr0:0x0210 lr0:0x9184
Task 0x0021, priority 1, in waitQueue, name "MainTask"
State: 4 (TS_WAIT)
Stack: Start 0x0030, size 0x200, in use 0x81, max used 0x168 (0x98 free)
Stack Trace: current PC 0x918f, IROM::rtos2[231]
Next: PC 0x4a74 @ stack 0x0096, PLAYFILE::main[139]
Next: PC 0x1e44 @ stack 0x008c, KERNEL::RunLibraryFunction[33]
Next: PC 0x4966 @ stack 0x0086, SHELL::main[47]
Next: PC 0x03c1 @ stack 0x007c, KERNEL::LoadDrivers[193]
Next: PC 0x049d @ stack 0x003e, KERNEL::main[157]
Next: PC 0x0087 @ stack 0x0032, KERNEL::startup[7]
Registers:
i0:0x0097 i1:0x0012 i2:0x0940 i3:0x0028
i4:0x0096 i5:0x0000 i6:0x00a3 i7:0xfc08
a2:0x0000 a1:0x0004 a0:0x8000 b2:0x0000 b1:0x0000 b0:0x0000
c2:0x0000 c1:0x00fa c0:0x00da d2:0x0000 d1:0x0000 d0:0x003c
p1:0x0000 p0:0x0000 ls:0x03cd le:0x03d8 lc:0x0000 mr0:0x0210 lr0:0x9184
Timer queue 0x0097 for task 0x0021 ("MainTask")
Tick count: 0x0017
Timer queue 0x1c1f for task 0x1c01 ("cyclic")
Tick count: 0x001c
Timer queue 0x02b6 for task 0x093c ("DECOD")
Tick count: 0x0001
For more information about Stop traces, see
here and
here.
There's another debugging feature that helps to detect calls to any library which has been already dropped from memory. Now any call to such library will result in a stop trace, identifying the problem.
Here's an example program that demonstrates this feature. It loads the program "LS", which is used to get directory listings of short file names, calls it, drops it and calls it again.
Code: Select all
ioresult main(char *parameters) {
void *lib = LoadLibrary("LS");
printf("Call1, this should be ok:\n");
RunLoadedFunction(lib,ENTRY_MAIN,(int)"S:"); //calls a lib
DropLibrary(lib);
printf("Call2, this should fail:\n");
RunLoadedFunction(lib,ENTRY_MAIN,(int)"S:"); //CALLS A DROPPED LIB!!!
}
And here's the result:
Code: Select all
S:>droptest
Call1, this should be ok:
[SYS] VS1005-E.FS CONFIG.TXT HELLO.MP3 VSOS.INI CONFIG.BAK SHELL.AP3
Call2, this should fail:
Call to dropped lib!
ZeroPtrCall from 7477(0x1d35) KERNEL::CallToDroppedLibrary[17]
i0=2178(0x0882) UNASSIGNED=4632(0x1218)
Task 0x0021, priority 1, in RUNNING, name "MainTask"
State: 3 (TS_READY)
Stack: Start 0x0030, size 0x200, in use 0xa1, max used 0x168 (0x98 free)
Stack Trace: current PC 0x3e85, Tasks::main[195]
Next: PC 0x1e2c @ stack 0x009e, KERNEL::RunLibraryFunction[33]
Next: PC 0x0b2f @ stack 0x0098, Zero Pointer Call Trap
Next: PC 0x3c91 @ stack 0x0091, DROPTEST::main[30]
Next: PC 0x1e2c @ stack 0x008c, KERNEL::RunLibraryFunction[33]
Next: PC 0x3bfc @ stack 0x0086, shell::main[47]
Next: PC 0x03bb @ stack 0x007c, KERNEL::LoadDrivers[193]
Next: PC 0x048e @ stack 0x003e, KERNEL::main[142]
Next: PC 0x0087 @ stack 0x0032, KERNEL::startup[7]
Task 0x1c01, priority 10, in waitQueue, name "cyclic"
State: 4 (TS_WAIT)
Stack: Start 0x1c10, size 0x100, in use 0x29, max used 0x3a (0xc6 free)
Stack Trace: current PC 0x918f, IROM::rtos2[231]
Next: PC 0x2b94 @ stack 0x1c1e, KERNEL::CyclicMainLoop[42]
Next: PC 0x90b5 @ stack 0x1c11, IROM::exit
Registers:
i0:0x1c1f i1:0x0012 i2:0x1b72 i3:0x1c08
i4:0x1c1e i5:0x0000 i6:0x1c2b i7:0xfc08
a2:0x0000 a1:0x0004 a0:0x8000 b2:0x0000 b1:0x0000 b0:0x0000
c2:0x0000 c1:0x0000 c0:0x0064 d2:0x0000 d1:0x0005 d0:0x0004
p1:0x0000 p0:0x0000 ls:0xebab le:0xffff lc:0x0000 mr0:0x0210 lr0:0x9184
Timer queue 0x1c1f for task 0x1c01 ("cyclic")
Tick count: 0x005e
Interrupts:
INT 0 INT_DAC , pri 2, vector 0x3611= auodac::DacInterrupt
INT 6 INT_MAC0 , pri 2, vector 0x384d= auiadc::AdcInterrupt
INT 12 INT_UART_TX , pri 1, vector 0x3154= uartin::UartTransmitInterrupt
INT 13 INT_UART_RX , pri 1, vector 0x3184= uartin::UartReceiveInterrupt
INT 15 INT_TIMER1 , pri 2, vector 0x2970= KERNEL::ApplyGFixes[49]
INT 16 INT_TIMER2 , pri 2, vector 0x2970= KERNEL::ApplyGFixes[49]
Starting POST-CRASH SHELL, be careful.
VSOS SHELL
S:>
S:>
From this Stop trace you can identify, that a call to a dropped library has occurred, and scanning the stack trace, you can see
DROPTEST::main[30] immediately after the
Zero Pointer Call Trap line. This gives you a clear indication that the program DROPTEST has done something bad in its function main().
This feature will help to detect if you have accidentally dropped a library which is still in use. Without this tracking feature, such calls are time bombs - they may appear to be working for a while, since the memory was not cleared, but crash afterwards at random locations, which is always very hard to trace. This tracking feature is implemented in the DropLibrary function by filling any code regions that are freed with JMPI operations to kernel function CallToDroppedLibrary, which prints out a message and then jumps to ZeroPtrCall, which gives the trace.
Ok, here's the important part:
For the trace to give best and most readable values, you need new versions of TRACE.DL3, INTTRACE.DL3, TASKS.DL3, VS1005G.SYM and KERNEL.SYM in your board's SYS directory. The KERNEL.SYM file is created whenever a new kernel is built; you must manually copy this file from your kernel source code folder to S:SYS/KERNEL.SYM to get correct traces. Otherwise the kernel function names either will not appear or will be incorrect. Symbols from assembly language code aren't properly displayed at the moment; that's why there may be some strange looking interrupt functions pointing to KERNEL::SomeIncorrectSymbol, don't be confused.
A new root image is also published, with new versions of the tracing tools and a few small updates here and there.
Happy hunting!
-Panu