Recent posts have been about debugging experiences. Jennifer and I have been working on a simple implementation of the RTEMS priority based scheduler to illustrate how to write an alternative scheduler. The primary RTEMS Scheduler is deterministic (e.g. constant, predictable) in performance because it uses a FIFO per priority and a two level bit map to assist in look ups. The simple scheduler uses a single list for all tasks and searches down the list to perform inserts. Its worst case is thus O(n) where n is the number of ready tasks. But this post is above debugging, not about the new scheduler. We will discuss that another time.
Jennifer and I want the simple scheduler to have 100% test coverage when it is merged. This has required us to run coverage analysis on RTEMS and check the results. We haven't yet merged this code so it isn't showing up in published runs. She noticed that thee method _Scheduler_priority_Enqueue_first was reported as never executed. We both found this incredulous since this is called as part of inheriting a priority. We knew this was well tested. She was perplexed and asked me what I thought. It turned out to be a recently introduced typo where _Scheduler_priority_Enqueue was configured as the handler for both the enqueue and enqueue entries points in the Scheduler Priority table. This also explained a couple of test failures Jennifer had noticed but hadn't investigated yet. This is the pertinent part of patch:
- _Scheduler_priority_Enqueue, /* enqueue_first entry point */ \
+ _Scheduler_priority_Enqueue_first, /* enqueue_first entry point */ \
Again, this problem was highlighted by an unexpected drop in the coverage results. RTEMS has very good test coverage and an unexpected change can indicate a problem. The fact that this method was never called was a huge hint to the cause. The answer popped almost instantly in my head. Debugging the test failures would almost certainly have taken much longer.
A blog of what I hope are interesting tales from the embedded software trenches. Interesting bugs, tricks, tips, etc.
Tuesday, March 8, 2011
Debugging an Invalid Memory Access
This time we have a guest at RTEMS Ramblings -- Chris Johns. Chris is a long time RTEMS contributor and member of the Steering Committee. He was the second person outside the core team to submit code to RTEMS. He has fielded some pretty impressive RTEMS applications. This is his discussion of he and I trying to track down an invalid memory access on the SPARC/SIS BSP. From here on.. "I" == Chris. :D
I have a SIS BSP failure with RTEMS head (+rbtree patch) and the latest tools on a MacOS host running the "Hello" sample application in the erc32 simulator. Joel is not seeing this so I have to dig into what has been a stable platform for me to developer the RTL code on. This is an account of the debugging session as I work though the problem.
I run the hello test and all I get is:
$ sparc-rtems4.11-run sparc-rtems4.11/c/sis/testsuites/samples/hello/hello.exe
Memory exception at ffffffe0 (illegal address)
Not much help from the tool. The same happens if I run the same application in gdb.
Setting a break point on boot_card and entering 'r' to run the application shows me the target is loading, booting then reaching the boot_card function. Nice because this means the tools are not broken and RTEMS and the BSP are sort of sane. I build the MacOS tools from source using the SpecBuilder tool and track Ralf's changes closely. This means there is always a chance something went wrong in the build. I have never seen this but there can always be a first time. I can step the code up to the API_Mutex_initialization call then something goes wrong but I am not sure where. Maybe I should look from the bottom up.
I decide to track down who is printing the error message "Memory exception ...". Running strings and grep on the executable shows it is not in RTEMS. I see it is generated by the simulator. I also see the simulator generates a trap 9 exception. This exception is not handled in the target so the simulator terminates. Fair enough but the stopped simulator destroys the state information of where the fault is which means I cannot see what happens.
A 'sparc-rtems4.11-objdump -D --source hello.exe | less' shows me trap 9 is address 0x2000090 so I set a break point with b *0x2000090 and run again. I break at the trap 9 entry point and stop the simulator exiting:
(gdb) c
Memory exception at ffffffe0 (illegal address)
Breakpoint 4, trap_table () at c/src/lib/libbsp/sparc/erc32/../../sparc/shared/start.S:68
68 BAD_TRAP; ! 09 data access exception
I can now inspect the state of the processor and try and find the source of the problem. First stop is a back trace:
(gdb) bt
#0 trap_table () at c/src /lib/libbsp/sparc/erc32/../../sparc/shared/start.S:68
Nothing helpful here. We know we are at this location and what we want is what happened before this.
I do not know SPARC processors very well and a dump of the registers gives me little information. I do know the stack works down and most processors save the return address on the stack. GDB is nice by providing me with the stack pointer as $sp. I dump the stack:
(gdb) x /32xw $sp
0x23ffcd0: 0x00000034 0x02007378 0x0200737c 0x00000008
0x23ffce0: 0x00002000 0x02014928 0x00000001 0x00000000
0x23ffcf0: 0x02012a30 0x02014924 0x02012a30 0x00006054
0x23ffd00: 0xffffffff 0x00000004 0x023ffd38 0x0200792c
0x23ffd10: 0x00000000 0x00000000 0x00000000 0x00000000
0x23ffd20: 0x00000000 0x00000000 0x00000000 0x00000000
0x23ffd30: 0x00000000 0x00000000 0x02012a30 0x00006089
0x23ffd40: 0x0201a9ac 0x00000008 0x020148b0 0x02014928
I have a separate window open with the sparc-rtems4.11-objdump output in less so I can search around with ease. With a few simple 'less' commands I can find the code at a specific address. The first address is '0x02007378' which must be the last one pushed. In less a '1G' takes me to the start of the dump then entering '/2007378' and enter brings up some code to do with the heap:
02007374 Heap_Protection_block_check_default:
static void _Heap_Protection_block_check_default(
Heap_Control *heap,
Heap_Block *block
)
{
2007374: 9d e3 bf a0 save %sp, -96, %sp
if (
2007378: c2 06 60 04 ld [ %i1 + 4 ], %g1
Dumping '$l1' gives:
(gdb) p /x $i1
$14 = 0xffffffdc
Dumping '$l1' gives:
(gdb) p /x $i1
$14 = 0xffffffdc
This is very close to the address in question. Time to run again this time with a break point on this address and a couple of displays to help me see what is happening:
(gdb) b *0x2007378
(gdb) display /i $pc
(gdb) display /x $i1
(gdb) r
The break point gets hit a number of times and the arguments all look ok so just continue. On the 6th hit of the breakpoint we get something that does not look ok:
(gdb) c
Breakpoint 8, _Heap_Protection_block_check_default (heap=0x2012a30, block=0xffffffdc) at c/src/../../cpukit/score/src/heap.c:149
149 if (
2: /x $i1 = 0xffffffdc
1: x/i $pc
=> 0x2007378 <_heap_protection_block_check>default+4>: ld [ %i1 + 4 ], %g1
A back trace this time is much better:
(gdb) bt
#0 _Heap_Protection_block_check_default (heap=0x2012a30, block=0xffffffdc) at c/src/../../cpukit/score/src/heap.c:149
#1 0x0200c82c in _Heap_Protection_block_check (heap=0x2012a30, alloc_begin_ptr=) at ../../cpukit/../../../sis/lib/include/rtems/score/heap.h:625
#2 _Heap_Free (heap=0x2012a30, alloc_begin_ptr=) at c/src/../../cpukit/score/src/heapfree.c:119
#3 0x02007d08 in _Objects_Extend_information (information=0x2012b18) at c/src/../../cpukit/score/src/objectextendinformation.c:224
#4 0x02006cc8 in _API_Mutex_Initialization (maximum_mutexes=1) at c/src/../../cpukit/score/src/apimutex.c:23
#5 0x0200672c in rtems_initialize_data_structures () at c/src/../../cpukit/sapi/src/exinit.c:125
#6 0x0200137c in boot_card (cmdline=) at c/src/lib/libbsp/sparc/erc32/../../shared/bootcard.c:163
#7 0x02001158 in zerobss () at c/src/lib/libbsp/sparc/erc32/../../sparc/shared/start.S:334
#8 0x02001158 in zerobss () at c/src/lib/libbsp/sparc/erc32/../../sparc/shared/start.S:334
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
Walking up the stack with the 'up' command until we end up in the _Object_Extend_information call:
(gdb) up
#3 0x02007d08 in _Objects_Extend_information (information=0x2012b18) at c/src/../../cpukit/score/src/objectextendinformation.c:224
224 _Workspace_Free( old_tables );
(gdb) p old_tables
$16 = (void *) 0x0
It would seem _Object_Extend_information is calling the workspace with a NULL which should be ok or it use to be ok. I chat with Joel and he informs me the code in the interface to the workspace heap has changed and this has exposed some bugs. A check of the code in the heap free call shows the heap protection check is being called before the block pointer has been validated. This also explains why Joel does not see the problem. I built RTEMS with the debug configure option. There are other cases so I will need to perform a careful check of all the heap code to make sure we are correct.
It looks like I am not the only one who has the problem. Peter Dufault has just posted to the RTEMS user list:
http://www.rtems.org/ml/rtems-users/2011/february/msg00142.html
The PR Peter has kindly raised is:
https://www.rtems.org/bugzilla/show_bug.cgi?id=1746
I was talking with Joel about the changes when I noticed the heap extend now allows discontinuous memory regions. I did not know this was allowed and I had been assuming the memory had to be continuous because of the code in _Heap_Is_block_in_heap. A check of rtems_region_extend shows it uses heap extend and its documentation states memory must be continuous. I have raised a PR to handle this:
https://www.rtems.org/bugzilla/show_bug.cgi?id=1747
Back to Joel.. Chris' discussion should provide some insight into how an free software project and community work. I made a modification to move some scattered NULL checks before calls to _Workspace_Free into that routine. Sebastian Huber noted that since NULL pointers shouldn't be processed by _Heap_Free, so the check was technically redundant so he removed it. This exposed a latent bug in _Heap_Free when passed an invalid address and debug checks were enabled. At the same time the Chris and I were tracking this down, a user tripped the same bug and filed a PR. In reviewing the code, Chris and I found other cases which could cause the same fault and a disconnect between extending the heap and checking whether a block was in the heap. This was a side-effect of recent enhancements and had never been caught by a user. So we see a community coding together, reviewing each other's code, and working together to resolve an issue.
It is important to note that this bug was only present in the RTEMS Development Head. It cannot occur in released versions.
I have a SIS BSP failure with RTEMS head (+rbtree patch) and the latest tools on a MacOS host running the "Hello" sample application in the erc32 simulator. Joel is not seeing this so I have to dig into what has been a stable platform for me to developer the RTL code on. This is an account of the debugging session as I work though the problem.
I run the hello test and all I get is:
$ sparc-rtems4.11-run sparc-rtems4.11/c/sis/testsuites/samples/hello/hello.exe
Memory exception at ffffffe0 (illegal address)
Not much help from the tool. The same happens if I run the same application in gdb.
Setting a break point on boot_card and entering 'r' to run the application shows me the target is loading, booting then reaching the boot_card function. Nice because this means the tools are not broken and RTEMS and the BSP are sort of sane. I build the MacOS tools from source using the SpecBuilder tool and track Ralf's changes closely. This means there is always a chance something went wrong in the build. I have never seen this but there can always be a first time. I can step the code up to the API_Mutex_initialization call then something goes wrong but I am not sure where. Maybe I should look from the bottom up.
I decide to track down who is printing the error message "Memory exception ...". Running strings and grep on the executable shows it is not in RTEMS. I see it is generated by the simulator. I also see the simulator generates a trap 9 exception. This exception is not handled in the target so the simulator terminates. Fair enough but the stopped simulator destroys the state information of where the fault is which means I cannot see what happens.
A 'sparc-rtems4.11-objdump -D --source hello.exe | less' shows me trap 9 is address 0x2000090 so I set a break point with b *0x2000090 and run again. I break at the trap 9 entry point and stop the simulator exiting:
(gdb) c
Memory exception at ffffffe0 (illegal address)
68 BAD_TRAP; ! 09 data access exception
I can now inspect the state of the processor and try and find the source of the problem. First stop is a back trace:
(gdb) bt
#0 trap_table () at c/src /lib/libbsp/sparc/erc32/../../
Nothing helpful here. We know we are at this location and what we want is what happened before this.
I do not know SPARC processors very well and a dump of the registers gives me little information. I do know the stack works down and most processors save the return address on the stack. GDB is nice by providing me with the stack pointer as $sp. I dump the stack:
(gdb) x /32xw $sp
0x23ffcd0: 0x00000034 0x02007378 0x0200737c 0x00000008
0x23ffce0: 0x00002000 0x02014928 0x00000001 0x00000000
0x23ffcf0: 0x02012a30 0x02014924 0x02012a30 0x00006054
0x23ffd00: 0xffffffff 0x00000004 0x023ffd38 0x0200792c
0x23ffd10: 0x00000000 0x00000000 0x00000000 0x00000000
0x23ffd20: 0x00000000 0x00000000 0x00000000 0x00000000
0x23ffd30: 0x00000000 0x00000000 0x02012a30 0x00006089
0x23ffd40: 0x0201a9ac 0x00000008 0x020148b0 0x02014928
I have a separate window open with the sparc-rtems4.11-objdump output in less so I can search around with ease. With a few simple 'less' commands I can find the code at a specific address. The first address is '0x02007378' which must be the last one pushed. In less a '1G' takes me to the start of the dump then entering '/2007378' and enter brings up some code to do with the heap:
02007374 Heap_Protection_block_check_default:
static void _Heap_Protection_block_check_default(
Heap_Control *heap,
Heap_Block *block
)
{
2007374: 9d e3 bf a0 save %sp, -96, %sp
if (
2007378: c2 06 60 04 ld [ %i1 + 4 ], %g1
Dumping '$l1' gives:
(gdb) p /x $i1
$14 = 0xffffffdc
Dumping '$l1' gives:
(gdb) p /x $i1
$14 = 0xffffffdc
This is very close to the address in question. Time to run again this time with a break point on this address and a couple of displays to help me see what is happening:
(gdb) b *0x2007378
(gdb) display /i $pc
(gdb) display /x $i1
(gdb) r
The break point gets hit a number of times and the arguments all look ok so just continue. On the 6th hit of the breakpoint we get something that does not look ok:
(gdb) c
Breakpoint 8, _Heap_Protection_block_check_
149 if (
2: /x $i1 = 0xffffffdc
1: x/i $pc
=> 0x2007378 <_heap_protection_block_check>
A back trace this time is much better:
(gdb) bt
#0 _Heap_Protection_block_check_default (heap=0x2012a30, block=0xffffffdc) at c/src/../../cpukit/score/src/heap.c:149
#1 0x0200c82c in _Heap_Protection_block_check (heap=0x2012a30, alloc_begin_ptr=
#2 _Heap_Free (heap=0x2012a30, alloc_begin_ptr=
#3 0x02007d08 in _Objects_Extend_information (information=0x2012b18) at c/src/../../cpukit/score/src/objectextendinformation.c:224
#4 0x02006cc8 in _API_Mutex_Initialization (maximum_mutexes=1) at c/src/../../cpukit/score/src/apimutex.c:23
#5 0x0200672c in rtems_initialize_data_structures () at c/src/../../cpukit/sapi/src/exinit.c:125
#6 0x0200137c in boot_card (cmdline=
#7 0x02001158 in zerobss () at c/src/lib/libbsp/sparc/erc32/../../sparc/shared/start.S:334
#8 0x02001158 in zerobss () at c/src/lib/libbsp/sparc/erc32/../../sparc/shared/start.S:334
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
Walking up the stack with the 'up' command until we end up in the _Object_Extend_information call:
(gdb) up
#3 0x02007d08 in _Objects_Extend_information (information=0x2012b18) at c/src/../../cpukit/score/src/
224 _Workspace_Free( old_tables );
(gdb) p old_tables
$16 = (void *) 0x0
It would seem _Object_Extend_information is calling the workspace with a NULL which should be ok or it use to be ok. I chat with Joel and he informs me the code in the interface to the workspace heap has changed and this has exposed some bugs. A check of the code in the heap free call shows the heap protection check is being called before the block pointer has been validated. This also explains why Joel does not see the problem. I built RTEMS with the debug configure option. There are other cases so I will need to perform a careful check of all the heap code to make sure we are correct.
It looks like I am not the only one who has the problem. Peter Dufault has just posted to the RTEMS user list:
http://www.rtems.org/ml/
The PR Peter has kindly raised is:
https://www.rtems.org/
I was talking with Joel about the changes when I noticed the heap extend now allows discontinuous memory regions. I did not know this was allowed and I had been assuming the memory had to be continuous because of the code in _Heap_Is_block_in_heap. A check of rtems_region_extend shows it uses heap extend and its documentation states memory must be continuous. I have raised a PR to handle this:
https://www.rtems.org/
Back to Joel.. Chris' discussion should provide some insight into how an free software project and community work. I made a modification to move some scattered NULL checks before calls to _Workspace_Free into that routine. Sebastian Huber noted that since NULL pointers shouldn't be processed by _Heap_Free, so the check was technically redundant so he removed it. This exposed a latent bug in _Heap_Free when passed an invalid address and debug checks were enabled. At the same time the Chris and I were tracking this down, a user tripped the same bug and filed a PR. In reviewing the code, Chris and I found other cases which could cause the same fault and a disconnect between extending the heap and checking whether a block was in the heap. This was a side-effect of recent enhancements and had never been caught by a user. So we see a community coding together, reviewing each other's code, and working together to resolve an issue.
It is important to note that this bug was only present in the RTEMS Development Head. It cannot occur in released versions.
Thursday, February 17, 2011
RTEMS Shell as a Debug Aid
Until the 4.9 release series, the RTEMS Shell was very primitive and only a few commands existed. Virtually no one used it. But with 4.9, the RTEMS Shell took a major leap forward with Chris Johns and I doing a lot of work on it. We added commands, command line history, command line editing, and simple scripting. You can use the shell from a serial port or via telnet. There are now approximately 100 standard commands with some such as ls, mv, cp, ln, and dd ported over from NetBSD. In addition, there are RTEMS specific commands to look at CPU usage per thread, stack usage, and rate monotonic period statistics. There are commands to examine the state of most RTEMS OS objects.
Chris Johns used the standard file related commands to great benefit when developing and debugging the RTEMS File System (RFS). He would mount remote NFS volumes and copy great quantities of data to an IDE hard disk. This allowed him to place stress on his new file system and even turned up a bug in the NFS client code.
But the most useful capability for developing and debugging user applications is probably the capability to include custom commands. These allow you to write commands which are specific to your hardware configuration or application. I have used this to capability to write a set of commands for the Winsystems PCM-MIO-G multi-function I/O PC-104 module. (Kudos to Winsystems for relicensing their GNU/Linux driver to be compatible with RTEMS licensing requirements.) This board has the following features:
[/] # pcmmio_din -i 10
Polling discrete inputs for 10 iterations with 1000 msec period
665:159912852 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000
669:238111788 0000 0000 1000 0000 0000 0000 0000 0000 0000 0000 0000 0000
671:250111878 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000
The board cam be configured such that when a discrete input changes an interrupt is generated. The device driver's interrupt handler determines the pin which changed, its current value and timestamps it using the Time Stamp Counter (TSC) register. This information is placed in a message buffer and send via an RTEMS Classic API Message Queue to an application task which is blocked waiting. This allows the application to know as precisely as possible when an input has changed and process that change at the task level. An example output of the pcmmio_irq command when using the push button (which bounces) is below:
[/] # pcmmio_irq -d -i 5
Polling for DIN IRQ for 5 iterations with 1000 msec period
1000 DIN irq pin 8 @ b9eba88c0e (0 usecs since last)
2000 DIN irq pin 8 @ b9eba932b2 (42 usecs since last)
3000 DIN irq pin 8 @ b9eba9c52e (37 usecs since last)
4000 DIN irq pin 8 @ b9ebadec4e (272 usecs since last)
4 total interrupts from DIN in 5000 milliseconds
In the above example, the command looked for interrupts for 5 iterations of a loop with a delay of 1000 milliseconds between iterations. But the interrupts from pushing the button and it bouncing occurred over a 272 microsecond period. In real application code, you would not put a long delay in between each check but block forever or with a reasonable timeout.
I could test analog output (DAC) by simply entering a command to write a value to a particular DAC channel using the pcmmio_dac command and verifying that the proper voltage was written using my multimeter.
[/] # pcmmio_dac 0 5
Write 5.0000 to to dac 0
The pcmmio_dac command has an interesting feature where you can http://pc104.winsystems.comwrite a "step" pattern. This steps from a low voltage to a high voltage using the specified step voltage and time between steps. When it reaches the high voltage, the command begins to step down. The following example illustrates using the pcmmio_dac command to write a step pattern to DAC 0. The pattern ranges from -2.5V to 2.5V with a .5V change every 250 milliseconds for a total of 10,000 milliseconds. When the voltage reaches 2.5V, the step will change to -.5V.
[/] # pcmmio_dac 0 -2.5 2.5 .5 250 10000
Write -2.5000-2.5000 step=0.5000 stepTime=250 msecs dac=0 max=10000 msecs
When testing analog input (ADC), I attached one DAC output to one ADC input. Then I used the command pcmmio_dac to write a voltage and pcmmio_adc to read a voltage. Just as pcmmio_din can monitor the discrete inputs for changes, the pcmmio_adc command can monitor the ADCs for changes in input. The following commands illustrate using this command to read all ADCs or just a single ADC a single time.
[/] # pcmmio_adc
1117:232053 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000
0.0000 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000
[/] # pcmmio_adc 0
1120:495519 0.0000
Note that in the above, the voltage read isn't the voltage that was written. There are a few potential reasons for this. First, I could have hooked things up wrong (but I checked and I didn't mess that up). Second, I could have gotten confused on the DAC and ADC channels I used. Yes, I did that a couple of times. But the final reason was that I forgot to initialize the channels for the input configuration I was using. This lead to the need for a command to configure an ADC channel.
Each ADC channel could be individually programmer for either single-ended or differential input, unipolar or bipolar voltage ranges and for 5V or 10V as the upper voltage in the range. I didn't want to enter sixteen commands by hand, so I added the feature where pcmmio_adc_mode can configure a contiguous range of ADC's to a particular setting. But this still could require multiple commands. With a flash of insight, I remembered that I could write a shell script to do this for me. This led to me writing the the following very simple shell script to configure the ADCs.
#! joel
echo "Setting all ADCs to +/-10V (bipolar) and single ended"
pcmmio_adc_mode 0 15
As mentioned earlier, to test the ADCs I had to write a voltage using the pcmmio_dac command and then read the voltage using the pcmmio_adc command. I wanted to run a series of voltages through the ADC but the step command didn't let me see the input between steps. I could have figured out a way to get access to the lines but I had used a pre-made jumper wire and didn't want to destroy it. So I wrote another simple shell script which repeated pcmmio_dac, sleep, pcmmio_adc commands. This allowed me to verify that a range of voltage could be written and read. The following is one set of the three commands. There were a lot more than this to have a script that ran for fifteen seconds.
pcmmio_dac 4 -2.0
sleep 1
pcmmio_adc 0
You might wonder how I got the shell scripts onto the target. Well I used another interesting feature of RTEMS. RTEMS has long has the In-Memory File System (IMFS) and the capability to load initial contents from a tar file image linked with the application. I simply wrote the scripts on my development machine and included them in the initial file system contents.
In using the RTEMS Shell and its ability to add custom commands, I was able to refactor the original GNU/Linux device driver, adapt it to RTEMS, add capabilities such as timeouts and timestamping input, and debug this device driver with very little difficulty. Plus these commands are now available for hardware integration and testing for this project and any other project that might use this device driver in the future.
Chris Johns used the standard file related commands to great benefit when developing and debugging the RTEMS File System (RFS). He would mount remote NFS volumes and copy great quantities of data to an IDE hard disk. This allowed him to place stress on his new file system and even turned up a bug in the NFS client code.
But the most useful capability for developing and debugging user applications is probably the capability to include custom commands. These allow you to write commands which are specific to your hardware configuration or application. I have used this to capability to write a set of commands for the Winsystems PCM-MIO-G multi-function I/O PC-104 module. (Kudos to Winsystems for relicensing their GNU/Linux driver to be compatible with RTEMS licensing requirements.) This board has the following features:
- Two 8-channel, 16-bit Analog-to-Digital (A/D)
- Two, 4-channel, 12-bit Digital-to-Analog (D/A)
- 48 Bidirectional I/O lines with interrupt support
- pcmmio_din - Read PCMMIO Discrete Inputs
- pcmmio_dout - Write PCMMIO Discrete Outputs
- pcmmio_adc - Read PCMMIO Analog Inputs
- pcmmio_adc_mode - Set PCMMIO Analog Input Modes
- pcmmio_dac - Write PCMMIO Analog Outputs
- pcmmio_irq - Wait for PCMMIO Interrupts
- pcmmio_bench - Benchmark PCMMIO Interrupts
[/] # pcmmio_din -i 10
Polling discrete inputs for 10 iterations with 1000 msec period
665:159912852 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000
669:238111788 0000 0000 1000 0000 0000 0000 0000 0000 0000 0000 0000 0000
671:250111878 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000
The board cam be configured such that when a discrete input changes an interrupt is generated. The device driver's interrupt handler determines the pin which changed, its current value and timestamps it using the Time Stamp Counter (TSC) register. This information is placed in a message buffer and send via an RTEMS Classic API Message Queue to an application task which is blocked waiting. This allows the application to know as precisely as possible when an input has changed and process that change at the task level. An example output of the pcmmio_irq command when using the push button (which bounces) is below:
[/] # pcmmio_irq -d -i 5
Polling for DIN IRQ for 5 iterations with 1000 msec period
1000 DIN irq pin 8 @ b9eba88c0e (0 usecs since last)
2000 DIN irq pin 8 @ b9eba932b2 (42 usecs since last)
3000 DIN irq pin 8 @ b9eba9c52e (37 usecs since last)
4000 DIN irq pin 8 @ b9ebadec4e (272 usecs since last)
4 total interrupts from DIN in 5000 milliseconds
In the above example, the command looked for interrupts for 5 iterations of a loop with a delay of 1000 milliseconds between iterations. But the interrupts from pushing the button and it bouncing occurred over a 272 microsecond period. In real application code, you would not put a long delay in between each check but block forever or with a reasonable timeout.
I could test analog output (DAC) by simply entering a command to write a value to a particular DAC channel using the pcmmio_dac command and verifying that the proper voltage was written using my multimeter.
[/] # pcmmio_dac 0 5
Write 5.0000 to to dac 0
The pcmmio_dac command has an interesting feature where you can http://pc104.winsystems.comwrite a "step" pattern. This steps from a low voltage to a high voltage using the specified step voltage and time between steps. When it reaches the high voltage, the command begins to step down. The following example illustrates using the pcmmio_dac command to write a step pattern to DAC 0. The pattern ranges from -2.5V to 2.5V with a .5V change every 250 milliseconds for a total of 10,000 milliseconds. When the voltage reaches 2.5V, the step will change to -.5V.
[/] # pcmmio_dac 0 -2.5 2.5 .5 250 10000
Write -2.5000-2.5000 step=0.5000 stepTime=250 msecs dac=0 max=10000 msecs
When testing analog input (ADC), I attached one DAC output to one ADC input. Then I used the command pcmmio_dac to write a voltage and pcmmio_adc to read a voltage. Just as pcmmio_din can monitor the discrete inputs for changes, the pcmmio_adc command can monitor the ADCs for changes in input. The following commands illustrate using this command to read all ADCs or just a single ADC a single time.
[/] # pcmmio_adc
1117:232053 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000
0.0000 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000 0.0000
[/] # pcmmio_adc 0
1120:495519 0.0000
Note that in the above, the voltage read isn't the voltage that was written. There are a few potential reasons for this. First, I could have hooked things up wrong (but I checked and I didn't mess that up). Second, I could have gotten confused on the DAC and ADC channels I used. Yes, I did that a couple of times. But the final reason was that I forgot to initialize the channels for the input configuration I was using. This lead to the need for a command to configure an ADC channel.
Each ADC channel could be individually programmer for either single-ended or differential input, unipolar or bipolar voltage ranges and for 5V or 10V as the upper voltage in the range. I didn't want to enter sixteen commands by hand, so I added the feature where pcmmio_adc_mode can configure a contiguous range of ADC's to a particular setting. But this still could require multiple commands. With a flash of insight, I remembered that I could write a shell script to do this for me. This led to me writing the the following very simple shell script to configure the ADCs.
#! joel
echo "Setting all ADCs to +/-10V (bipolar) and single ended"
pcmmio_adc_mode 0 15
As mentioned earlier, to test the ADCs I had to write a voltage using the pcmmio_dac command and then read the voltage using the pcmmio_adc command. I wanted to run a series of voltages through the ADC but the step command didn't let me see the input between steps. I could have figured out a way to get access to the lines but I had used a pre-made jumper wire and didn't want to destroy it. So I wrote another simple shell script which repeated pcmmio_dac, sleep, pcmmio_adc commands. This allowed me to verify that a range of voltage could be written and read. The following is one set of the three commands. There were a lot more than this to have a script that ran for fifteen seconds.
pcmmio_dac 4 -2.0
sleep 1
pcmmio_adc 0
You might wonder how I got the shell scripts onto the target. Well I used another interesting feature of RTEMS. RTEMS has long has the In-Memory File System (IMFS) and the capability to load initial contents from a tar file image linked with the application. I simply wrote the scripts on my development machine and included them in the initial file system contents.
In using the RTEMS Shell and its ability to add custom commands, I was able to refactor the original GNU/Linux device driver, adapt it to RTEMS, add capabilities such as timeouts and timestamping input, and debug this device driver with very little difficulty. Plus these commands are now available for hardware integration and testing for this project and any other project that might use this device driver in the future.
Wednesday, October 20, 2010
Running SLOCount on RTEMS
SLOC is everyone's favorite metric to hate but it is fun to discuss anyway. I recently ran David Wheeler's SLOCCount [1] on RTEMS and thought I would pass along some of the results. There is an RPM available for Fedora so I started with that. But I found a bug in which it counted our assembly include files as Pascal. Needless to say there is no Pascal in RTEMS so I fixed that. If anyone wants the patch, I am happy to provide it.
The first part of the report from this program is a breakdown of the source code by language. This showed the following breakdown based upon programming language:
No real surprise there. RTEMS is mostly in C and high level languages with assembly language primarily for context switch and interrupt dispatching. With over a dozen active ports on the CVS head, it is no shock there is 39.5K of well commented assembly language.
The Shell and Perl is primarily for configuration and build infrastructure.
The second part of the output from sloccount is related to the estimated cost of producing the software and how many man years it would take. Using a rough estimate of 100K USD salary for each software developer implementing RTEMS, sloccount estimates RTEMS would require about 205 person-years to recreate at an estimated cost of 49.2M USD.
That makes RTEMS a great bargain! You are getting very high quality software that would cost a sizeable fortune to reinvent. IUnfortunately, the RTEMS team doesn't have $49,000,000 so please consider using the services of the core developers. That's how we pay the bills and keep the kids from going hungry.
Enjoy the gift of RTEMS!
--joel
[1] Per David's request, this data was "generated using David A. Wheeler's 'SLOCCount'."
The first part of the report from this program is a breakdown of the source code by language. This showed the following breakdown based upon programming language:
ansic: 644676 (87.49%)
asm: 39569 (5.37%)
ada: 27563 (3.74%)
sh: 18204 (2.47%)
cpp: 5236 (0.71%)
perl: 1623 (0.22%)
No real surprise there. RTEMS is mostly in C and high level languages with assembly language primarily for context switch and interrupt dispatching. With over a dozen active ports on the CVS head, it is no shock there is 39.5K of well commented assembly language.
The Shell and Perl is primarily for configuration and build infrastructure.
The second part of the output from sloccount is related to the estimated cost of producing the software and how many man years it would take. Using a rough estimate of 100K USD salary for each software developer implementing RTEMS, sloccount estimates RTEMS would require about 205 person-years to recreate at an estimated cost of 49.2M USD.
Total Physical Source Lines of Code (SLOC) = 736,871
Development Effort Estimate, Person-Years (Person-Months) = 205.02 (2,460.21)
(Basic COCOMO model, Person-Months = 2.4 * (KSLOC**1.05))
Schedule Estimate, Years (Months) = 4.05 (48.59)
(Basic COCOMO model, Months = 2.5 * (person-months**0.38))
Estimated Average Number of Developers (Effort/Schedule) = 50.64
Total Estimated Cost to Develop = $ 49,204,211
(average salary = $100,000/year, overhead = 2.40).
That makes RTEMS a great bargain! You are getting very high quality software that would cost a sizeable fortune to reinvent. IUnfortunately, the RTEMS team doesn't have $49,000,000 so please consider using the services of the core developers. That's how we pay the bills and keep the kids from going hungry.
Enjoy the gift of RTEMS!
--joel
[1] Per David's request, this data was "generated using David A. Wheeler's 'SLOCCount'."
Friday, August 20, 2010
When Does a GSOC Project End?
Today is the deadline for turning in student evaluations for the 2010 edition of the Google Summer of Code. The RTEMS Project was fortunate enough to have eight students this year and they all did great work. Some of it is still not merged and some needs some polish and love before being production ready. But it looks like all the students successfully met their goals. Personally, I am proud of all the students this year.
So the GSOC 2010 program is nearing its official end and it is tempting for the students to consider their work as over and end their involvement with RTEMS. But that's not the goal of GSOC nor is it desirable from an RTEMS perspective. All projects participating in GSOC want code written during the summer but they also really want long-term contributors. So this is not an end, it is a transition. What do you do next?
As a minimum, you need to work with the mentors to get your code merged into the various projects, functional, documented, and tested. We want your code to be part of the RTEMS experience moving forward. This is not a classroom exercise where the code is thrown away.
Last year, I told someone that you really should make your goal that you should be proud of what is merged and available. You should be able to cite this work as an example of what you are capable of to future employers and graduate schools. Just as all FOSS developers take pride in their work, you should also. Work with us to help get it to that point.
We would like to see you all continue your involvement. This would give you a chance to see YOUR work being used by real world applications. Your involvement does not have to be limited to the area of your GSOC project. RTEMS is a broad project and you can work on something else if that is what you want to do. It is also perfectly acceptable to simply continue to work to perfect your submission. We strive for 100% test coverage, great documentation and exceptional performance. Those are hard to achieve in a first implementation of anything.
So students, do not disappear. Stay involved.
So the GSOC 2010 program is nearing its official end and it is tempting for the students to consider their work as over and end their involvement with RTEMS. But that's not the goal of GSOC nor is it desirable from an RTEMS perspective. All projects participating in GSOC want code written during the summer but they also really want long-term contributors. So this is not an end, it is a transition. What do you do next?
As a minimum, you need to work with the mentors to get your code merged into the various projects, functional, documented, and tested. We want your code to be part of the RTEMS experience moving forward. This is not a classroom exercise where the code is thrown away.
Last year, I told someone that you really should make your goal that you should be proud of what is merged and available. You should be able to cite this work as an example of what you are capable of to future employers and graduate schools. Just as all FOSS developers take pride in their work, you should also. Work with us to help get it to that point.
We would like to see you all continue your involvement. This would give you a chance to see YOUR work being used by real world applications. Your involvement does not have to be limited to the area of your GSOC project. RTEMS is a broad project and you can work on something else if that is what you want to do. It is also perfectly acceptable to simply continue to work to perfect your submission. We strive for 100% test coverage, great documentation and exceptional performance. Those are hard to achieve in a first implementation of anything.
So students, do not disappear. Stay involved.
Friday, June 4, 2010
May -- A TIme of Beginnings and Endings
For still in school or who have children in school, May is always an interesting and busy month. It was the end of another academic year for my four children and the end of high school for two of them. It is the anniversary month for my high school, Bachelors and PhD graduations. At the high school graduation commencement, we were once again reminded by the speaker that commencement is a ceremony to celebrate the end of one thing and the beginning of another. It is more a recognition of a milepost on a journey than a goal in itself. At this point, you are probably asking yourself what this has to do with software and the answer is nothing and everything.
A successful software project lives on -- it is not something that is ever complete. Each release announcement is comparable to a graduation commencement. It captures what we have done and is just a milepost. It is a useful milepost in the software world because it represents a completion point. It is a recognizable measure like a diploma that means that the software has passed some measure of completeness and quality.
RTEMS is now over twenty years old. It is the same age as my daughter who is entering her senior year in college. It has matured just as she has. It has gotten more capabilities just as my children have learned more. It is smarter and more efficient than it was. My children are also somewhat more self-sufficient (not efficient yet) but I can hope. RTEMS is in many ways my first child. I was there at the birth. I held its hand as it moved from a research project to an independent free software project.
Today I cut the 4.10 release branch. This represents a major milestone in the life of RTEMS. I can say with certainty and the pride of a parent that this is the best release branch so far. With both coverage testing and the daily builder, the testing has improvement markedly over the past few years. We have automated testing for all of the GNU tools we use. We have overhauled the main web site to be more modern looking and hopefully friendlier. The core technical content was largely unchanged from the older site so this is a lot like a girl getting a make-over before a school dance.
But just as with a graduation commencement, there is a past and a future. The future for RTEMS includes both maturation and additional capabilities. I want to see the RTEMS Project mature its processes by further expand our automated testing and improve the patch review and merge process. I want to see RTEMS grow in capability and I know this is going to happen because there are multiple interesting efforts waiting to be reviewed and merged. There is a SPARC64 port with multiple BSPs, a USB stack, a port of the LWIP stack, and my work on symmetric multiprocesssing support for RTEMS.
So remember that life is full of milestones but those are also points of reflection and landings from which one can climb to the next level. So reflect a bit on 4.10 and look forward to what RTEMS 4.11 or 5.0 will look like. I am excited and hope you are too.
A successful software project lives on -- it is not something that is ever complete. Each release announcement is comparable to a graduation commencement. It captures what we have done and is just a milepost. It is a useful milepost in the software world because it represents a completion point. It is a recognizable measure like a diploma that means that the software has passed some measure of completeness and quality.
RTEMS is now over twenty years old. It is the same age as my daughter who is entering her senior year in college. It has matured just as she has. It has gotten more capabilities just as my children have learned more. It is smarter and more efficient than it was. My children are also somewhat more self-sufficient (not efficient yet) but I can hope. RTEMS is in many ways my first child. I was there at the birth. I held its hand as it moved from a research project to an independent free software project.
Today I cut the 4.10 release branch. This represents a major milestone in the life of RTEMS. I can say with certainty and the pride of a parent that this is the best release branch so far. With both coverage testing and the daily builder, the testing has improvement markedly over the past few years. We have automated testing for all of the GNU tools we use. We have overhauled the main web site to be more modern looking and hopefully friendlier. The core technical content was largely unchanged from the older site so this is a lot like a girl getting a make-over before a school dance.
But just as with a graduation commencement, there is a past and a future. The future for RTEMS includes both maturation and additional capabilities. I want to see the RTEMS Project mature its processes by further expand our automated testing and improve the patch review and merge process. I want to see RTEMS grow in capability and I know this is going to happen because there are multiple interesting efforts waiting to be reviewed and merged. There is a SPARC64 port with multiple BSPs, a USB stack, a port of the LWIP stack, and my work on symmetric multiprocesssing support for RTEMS.
So remember that life is full of milestones but those are also points of reflection and landings from which one can climb to the next level. So reflect a bit on 4.10 and look forward to what RTEMS 4.11 or 5.0 will look like. I am excited and hope you are too.
Tuesday, May 4, 2010
RTEMS SMP Exploration #1
Many of you know that I have been working on an SMP design for RTEMS for a couple of years now as a background activity. This has been a slow project and I have been wanting to work on it more but it has been almost entirely volunteer activity on my part. But recently, the activity level has picked up. Gedare Bloom's GSOC proposal Modular SuperCore Scheduler Manager will make a significant dent in the work required to support SMP. Currently, there is no discrete Scheduler component in the RTEMS SuperCore and a big part of supporting SMP is to have a single processor and an SMP-aware scheduler. To properly support this, there has to be a discrete Scheduler component in the SuperCore and a mechanism to select alternate schedulers. Gedare's project is to refactor the existing code base and provide a SuperCore Scheduler Handler along with the configuration required. Gedare has previously implemented an Earliest Deadline First (EDF) Scheduler for RTEMS and we are planning for this to be available as one of the alternative schedulers. Tiny/RTEMS may even benefit because it may make sense to have a light-weight scheduler algorithm for lower end target processors.
With Gedare focusing on refactoring the Scheduler, I have felt free to focus on the process of initializing a multicore processor, interprocessor interrupts, spinlocks, and transferring control to the first thread on a secondary core. I have succeeded in demonstrating these on pc386 with up to 32 cores and on SPARC/LEON3 with four cores. This work has let me work through the definition of a per CPU OS structure as well as the BSP/RTEMS SMP Interface. If you are interested in experimenting with this on another architecture, let me know.
I am looking forward to working this summer with Gedare and seeing how close we get to SMP RTEMS support before the 2010 Summer of Code is over.
With Gedare focusing on refactoring the Scheduler, I have felt free to focus on the process of initializing a multicore processor, interprocessor interrupts, spinlocks, and transferring control to the first thread on a secondary core. I have succeeded in demonstrating these on pc386 with up to 32 cores and on SPARC/LEON3 with four cores. This work has let me work through the definition of a per CPU OS structure as well as the BSP/RTEMS SMP Interface. If you are interested in experimenting with this on another architecture, let me know.
I am looking forward to working this summer with Gedare and seeing how close we get to SMP RTEMS support before the 2010 Summer of Code is over.
Subscribe to:
Posts (Atom)