Terrible Storm and RTEMS Outage

Surely by now, you have noticed that the RTEMS Project appeared to drop completely off the face of the planet about 6pm CST April 27.  It was at this time that the third storm system moved through north Alabama and knocked out all major power transmission lines.  This blog is a first in a series to let you all know what happened and what is happening now.

The primary servers and lab machines for the RTEMS Project (.org and .com) are in Huntsville Alabama which was in the path of the storm April 27th 2011. This storm  killed 340+ across multiple states and left a huge trail of destruction.  I have heard reports of business signs being found 100 miles (160km) away.  The following is a nice weather summary without the heart wrenching photos of the death and devastation.

http://www.washingtonpost.com/blogs/capital-weather-gang/post/alabama-tornado-outbreak-visuals-jaw-dropping-radar-and-satellite-imagery/2011/04/29/AFg1C5YF_blog.html

Huntsville had three systems pass over it that day. The first was nasty but no issues impacting the server or our home. The second system resulted in water getting into the rtems.info server area but we still had power. This allowed us to clean up and get the server back online until the third system hit. The third system was the killer. It was the devastating one that wiped out communities from Mississippi through Alabama and Georgia to points further north. It destroyed the major power transmission lines into north Alabama and Mississippi. Local utilities get power from the Tennessee Valley Authority (TVA) and TVA could not supply power to them. Their blog is here with details:

http://www.tva.com/news/releases/aprjun11/storm.htm


I was teaching an RTEMS class during this with the sole attendee being a wonderful fellow from the UK.  We spent much of Wednesday in a safe area inside OAR.  And once the storm had passed and we realized we were the lucky ones, we finished the class without power.  His hotel room was wet and without power but his bed was dry.  He could charge his laptop from the car.  We took a table and a couple of chairs from OAR and sat outside the door.  When the sun moved and we got hot,  we moved the furniture.  At one point, we were on the other side of the parking lot.  We had nothing else to do and a dusk to dawn curfew, so we followed the class material, chatted, drank soda, etc.. Just chilled and did RTEMS stuff.  Phillip deserves a big thank you for helping me make sure all was turned off Thursday and cleaning the fridge and freezer Friday. I sent him to Chattanooga for the weekend and I hope it was some nice relaxing site-seeing.

Friday, my family went to a hotel in a neighbouring city and waited for power to be restored. We came home Monday afternoon since our home had no apparent damage and power was restored.  We are near the main hospital so we usually get power early.  I started ensuring the rtems.info and elviscostellofans.com server came back up OK. Michele is cleaning the fridge and freezer out. If we didn't lose any electronics due to power spikes, then that's all I think we have. That makes us very lucky. Michele and I know people with deaths in their families or homes destroyed. Cleaning the fridge looks pretty tame in comparison.

We tried to stay in touch using our cell phones for email but the towers died about 12 hours in.  Plus if we didn't know you on Facebook or via our private emails, it looked like we disappeared.  I apologize for not remembering linkedin and the RTEMS facebook group.  I didn't even remember IRC until Friday when we got to the hotel.

Huntsville Utilities announced yesterday (Monday night) that they have done all they can.  Everywhere TVA has given them power has been passed on to residents.  Only 30% have power.  I believe that Redstone Arsenal, Marshall Space Flight Center, and Research Park will be the last in the area to be restored.  They consume a LOT of power between them and it is more important to get power back to houses.

We really appreciate the good karma that was sent our way. We are both tired and frazzled but that's no biggie.

More RTEMS SMP Patches Coming

Some of you may be aware that SMP for RTEMS has been underway for about a year now.  The goal of the SMP effort is to have a simple, working, and correct implementation.  The first incarnation will have the following characteristics.

• BSP SMP Interface definition with implementations for
• PC386
• LEON3
• Simple SMP Aware Priority Based Scheduler
• Faithful SMP safe version of RTEMS OS Critical Sections
• Dispatch Disable
• Interrupt Disable
• Scheduler Simulator 
• Test scenarios for new Simple SMP Scheduler
• Features Not Present
• Processor affinity
• Deferred Floating Point context switch
• Taking a core offline

The SMP implementation plan broken the effort into as many small steps as possible so it could be incrementally reviewed and merged.  This plan also allows for intermittent work.  This was critical due to the fact that all initial work was completely volunteer.  In addition to being planned as a series of small steps, the initial SMP implementation is focused on simplicity and correctness.  We can improve a simple working implementation.

Gedare Bloom and I made the first steps last summer when implemented the Pluggable Scheduler Framework for RTEMS and I added a "per cpu" data structure.  Together these allow us to provide an alternative scheduler that is SMP aware and to have the data required by RTEMS SuperCore to manage each core encapsulated and allocated properly.

Jennifer Averett and I have been working the past couple of months on completing the SMP support to RTEMS.   Jennifer and I are approaching a milestone of having a basic SMP system functional with the only major missing item being SMP safe interrupt disable sections.  We are about to file a set of PRs and merge our current work and it made sense to post a blog entry with status that the PRs could reference.

• Test code - our test code is hacky since it has to force interprocessor interrupts. We need to integrate where these are generated   inside RTEMS.  Tests will be submitted once the code is in shape to work without "user-level" intervention.
• Simple SMP Scheduler - implemented, tested with schedsim and our hacky test
• Scheduler Simulator - multiple changes to improve its use during Scheduler development and to track changes in code base
• PC386 BSP - SMP BSP support seems complete.
• LEON3 BSP - SMP BSP support seems complete.
• Context Switch Disable Critical Section - Working

Overall, (today) SMP RTEMS  can bring an SMP system out of reset, schedule across multiple cores, and command the first dispatch on the secondary cores.  The "disable dispatch" should be SMP safe now.  It can do this on pc386 and leon3.

The next major tasks are to integrate the generation of interprocessor interrupts for subsequent dispatch requests and system shutdown.  We also have to address interrupt disable SMP safety.

We are doing our best to break this into as many small incremental pieces as possible so the review and integration into the main tree is easier.

Behind the Scenes of the RTEMS Tool Binaries

I recently posted a long email to the RTEMS Users mailing list about what went into the building and distribution of the pre-built RTEMS Cross Development Tools.  I thought it would be interesting to clean that post up and turn it into a blog entry for posterity. 

I don't think most people in the community realize what goes on quietly behind the scenes for the tools. When someone installs a pre-built toolset, it is the result of Ralf Corsepius' ongoing effort. 

OAR hosts the RTEMS Build Farm and Ralf uses these machines to build the tools. When there is a change in a patch or tool revision, he very quickly responds and kicks off tool builds. I have no idea how long it takes for them to finish building but the number of individual toolset combinations is staggering when you consider the multipliers:

• number of target architectures (~10-12 depending on RTEMS version)
• number of host OS distributions and version
• SUSE
• CentOS/RHEL
• Fedora
• mingw32 
• Cygwin
• 32 and 64 bit hosts

Today there are 15 unique host variations for 4.11. This results in approximately 25GB of tool content for 4.11 on ftp.rtems.org. In addition, there are binary toolsets on the ftp site for release branches back to 4.6.  So the main ftp site has a LOT of stuff on it.

Ralf is very quick about getting new tool binaries out. Because of this, RTEMS is typically the first project to release binary tools after a binutils, gcc, or gdb release.  For gcc 4.6.0, he tracked the final release candidates so we were using the release image before the announcement. :-D 

After the tools land on the RTEMS FTP site, there are two yum mirrors of the rtems.org site:

rtems.eu [1]
rtems.info [2]

It can take hours for the mirror process to complete. Ralf has a script that checks the mirrors each hour.  This script emails those interested when things get out of sync.  The Yum repository for each RTEMS branch, distribution, OS version, and 32/64-bit variation is checked individually.  When a mirror out of sync for a variation, that single mirror is taken out of the yum mirror list for that variation until it has time to resynchronize. When a tool build is under way, I might get email for 8+ hours showing the progress of the synchronization.

Check out the Munin performance graphs for rtems.info to see how long a recent tool mirroring took.

This is what goes on behind the scenes to make the tool binaries available.  There is a different process for building the various tool chains, running the tests on them and reporting them to both the RTEMS Tool Test Results and GCC Test Results mailing lists.

If you would be interested in DVD distributions of the pre-built tools, let me know.

--joel

[1] rtems.eu is sponsored by Embedded Brains. I don't know its speed.

[2] rtems.info is my personal server and is sponsored by love and donations. It is an 8/1 Mbps connection which could be upgraded.

Merging Multiple PDF Files

If you have taken one of the RTEMS Classes from me, you will remember that the material for the Open Class comprises over 1000 PowerPoint slides. [1]  These slides are broken down into sections and within each section, there is a unit of 20-100 slides.  Each unit is an individual file.  Getting from 50+ PowerPoint files to printed material is a tedious and error prone process by hand.  The class and this process have evolved over the past ten years.  In this post, I will provide some insight into how this is done.

The first piece of magic is an MS-Office macro written by someone here are OAR.  It reads in a list of files from a text file.  The files are in the order they are to be printed.  This macro automates either generating PDFs or directly printing the files in the various handout formats (1 per page, 3 per page, 6 per page, etc.).  The PDFs are generated using PDFCreator which makes it possible to specify a unique file name for each PDF file.  The PDF files are prepended with a number so they sort and print in the correct order when wild-carded.  This produces files like this:

001-OpenClass.pdf
002-IntroToRTEMS.pdf
003-ProfilesAndRTEMS.pdf
...

Once the PDF files are generated, they can be printed easily.  However, I sometimes teach the class in Munich and have to send the PDFs to the nice folks embedded brains GmbH  to print there.  For the first few classes, there I sent them a large number of PDFs.  When someone dropped the master copy, we learned it didn't have page numbers.  This taught us to add page numbers. :-D

But this still leaves us with a large number of PDFs.  The solution to this was a custom  shell script that merges them into proper double-sided "units".  Each unit is then a single PDF file which goes between divider tabs in a binder.  Now there are seven PDF files for the Open Class and each page is numbered.  Much safer and easier.

The script to merge the PDF files was developed and executes on GNU/Linux (no surprise, right?).  The key to this program is this shell function:

merge_them()
{
  outf=$1
  shift
  inf=$*
  gs -dNOPAUSE -sDEVICE=pdfwrite -sOUTPUTFILE=${outf} -dBATCH ${inf}
}

This function takes the name of output file as the first argument and the set of PDF files to merge as the rest of the arguments.  When invoked, the command looks something like this in my shell script:

merge_them ${mergedir}/01-Intro.pdf 00[1-5]*.pdf

That takes the first five "section" PDF files and merges them to produce the PDF file named 01-Intro.pdf for the Introduction to RTEMS "unit".  This file  is  placed in the output directory ${mergedir}.  This is repeated for each of the units in the class.

But remember -- I want to produce a double-sided master copy.  Sometimes, the merged PDF files for a unit will have an odd number of pages.  The script has another section to detect merged PDFs with odd number of pages and add a page the says "Intentionally Blank"  [2]  The following fragment of the shell script determines how many pages are in the PDF file. If the number of pages is odd, it them adds the Intentionally Blank PDF file.

pages=`pdfinfo $1 | grep Pages | cut -d':' -f2`
remainder=`expr ${pages} % 2`
if [ ${remainder} = 1 ] ; then
   mv $1 XXX.pdf
   merge_them $1 XXX.pdf ${BLANKPDF}
   rm -f XXX.pdf
fi

And that's it.  It only takes about a minute to run and produces double-sided files that are very easy to send to a printer.  We have a nice duplex printer and by using paper that is already 3-hole punched, constructing the material for the RTEMS classes is much simpler than it was 10 years ago.

--joel

[1] OpenOffice did not exist when the slides were created.  I have tried to use OpenOffice with them, but it butchers the slides and destroys. them.  If this is ever resolved, I will happily use OpenOffice for the class.

[2] The "Intentionally Blank" page was generated in OpenOffice. :D

A Close Look at a Funny Spam

I get a lot of spam.  And when I say a lot, I really mean it.  Most of it is caught by the OAR spam filter but I have to have them keep my settings down a bit to ensure I always get random sales inquiries.  I have had the same email address for over 15 years and am very open about it.  I post to free software development mailing lists and sometimes those get archived with email addresses.  When people get viruses, they have my email from those lists or personal correspondence.  So I have received dating and penis enlargement spam that is supposedly from people who would die if they knew.  I generally just delete it quickly but sometimes read it.

This morning, I received this gem.  I changed the return address and the phone numbers.

Received: from [32.11.46.109] (helo=tdyoireznpl.tmxmykph.ua)
Subject: Free heroin shipping!

FREE HEROIN SHIPPING!

1. Heroin, in liquid and crystal form.
2. Rocket fuel and Tomohawk rockets (serious enquiries only).
4. New shipment of cocaine has arrived, buy 9 grams and get 10th for free.

Everebody welcome, but not US citizens, sorry.

ATTENTION. Clearance offer. Buy 30 grams of heroin, get 5 free.

Please contact: SPAMMER_EMAIL@gmail.com

PHONE 0093(0)1234567
FAX 0093(0)1234567

Afghanistan

There are so many things to notice.  The incorrect spellings and numbering (1, 2, 4) are how they arrived.   The interesting mix of drug spam and weapon spam.

On the technical side, they claim to be from Afghanistan and the 0093 country code is for Afghanistan but the email address listed is gmail (frowny face to them), the "helo" exchange with the mail service indicates it came from .ua which is the Ukraine.  But the IP address listed is neither of those.  The IP address is allocated to .... are you ready...

OrgName:        AT&T Global Network Services, LLC

OrgId:          ATGS

Address:        3200 Lake Emma Road

City:           Lake Mary

StateProv:      FL

PostalCode:     32746

Country:        US

So we have spam from Florida, claiming to be from the Ukraine, and wanting us to contact some drug/weapon runner in Afghanistan.  My guess is that this is likely spam from one of those infamous Russian botnets driven by the Russian mob.

The marketing and salesmanship is brilliant in a warped way. You have to smile at the offer of free shipping and buying 9 grams and get one free.  And who could resist the Clearance offer?  All we are missing is an order by midnight tonight and the more you buy, the more you save.

The pinnacle of the marketing here is that this offer is not available for American citizens.  Wow!  What a great use of reverse psychology.  Now all of the Americans reading this spam want the drugs with free shipping and a six-pack of "Tomohawk" missiles.  Hold me back. 

This is nothing I will reply and it is already deleted but very entertaining to read. This is even funnier than the offer I got recently which was supposed to be from an RTEMS Steering Committee member and slipped through the the RTEMS Users mailing list this week.  It wanted us all to look at their photo set at a Russian "sex flirt girls" site.  I really hope they were not pictures of him. LOL

Coverage Testing Finds Unexpected Bug

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.

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 &#60_heap_protection_block_check>default+4&#62: 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.