A Case Study on Finding, Fixing, and Testing a Firmware Bug Without Hardware

I previously wrote about a client project that I quickly adapted to enable TDD and unit testing. I received a bug report from our client, and I was able to identify the issue, verify the fix, and make a release without turning on any hardware. I hope this article demonstrates the power of having a hardware-independent test suite for your embedded project.

Everything below was written in lock-step with my test-driven investigation. Here’s the general algorithm you will see play out:

  • I started by reviewing the bug report, reviewing the documentation, and forming a hypothesis
  • Before looking for the problem, I created a failing test and confirmed I received the same result as my client
  • I used my hypothesis to narrow in on the problem code
  • I created a fix that I believed addressed the problem
  • I ran the test suite to that the failing test was now passing, and no other tests were broken
  • I released the new code to the client

Let’s dive in.

Table of Contents:

  1. Setting the Scene
  2. The Bug
  3. Adding a Failing Test
  4. Finding the Problem
  5. Making a Fix
  6. Verifying the Fix
  7. Release
  8. Feedback
  9. Takeaways
  10. Further Reading

Setting the Scene

Here are the basic details you need to know about the FLEX paging protocol to help set the scene for this article:

  • FLEX data cycles are 4 minutes long
  • The cycles are broken up into 128 frames
  • A pager can be instructed to listen to a subset of these frames (often just one)
    • In order to preserve battery life, a pager listening for a single address only needs to wake up every 4 minutes to receive its particular frame
  • FLEX supports multiple transmission modes:
    • 2-FSK 1600bps
    • 2-FSK 3200bps
    • 4-FSK 1600bps (aka 3200bps, since a dibit pair is transmitted per unit of signal time with 4-FSK)
    • 4-FSK 3200bps (aka 6400bps)
  • With higher data rates, the data cycle and frame times don’t change
    • Instead, more data is transmitted in the same frame, and the extra data is in a different “phase”
    • 2-FSK 1600bps is the lowest speed, and it transmits one phase per frame
    • 2-FSK 3200bps and 4-FSK 1600bps transmit two phases per frame
    • 4-FSK 3200bps transmits four phases per frame
  • Pagers are assigned an address, known as a “capcode”
    • Capcodes can be short or long, and there are different numeric ranges assigned to each

The Bug

My client was sending FLEX messages from test transmitter equipment that automatically encodes pages. Messages were properly received and decoded when sending in 2-FSK 1600bps mode, but when sending in 2-FSK 3200bps mode failures were occurring.

I was unable to reproduce the issue with my hardware setup, and we noticed that we had different firmware versions for our test equipment. After upgrading the firmware, my client noticed the failure still occurred and pinpointed it to the pager capcode he was using.

During my testing, I was using a long capcode: “A123456789”, and he was using a short capcode: “A1588792”. The initial hypothesis was that the bug was tied to short vs long capcodes, but I already had a test case that was successfully decoding messages from a short capcode. Curious indeed.

After consulting the FLEX specification, I learned that the capcode value informs the pager about where in the FLEX cycle its data will be found:

The standard procedure for deriving the phase and frame values from the CAPCODE starts by separating the 7 or 9 digit decimal address portion and performing a decimal to binary conversion. The least significant bit is labeled “bit 0”, in order the following “bits 2 and 3” specify phases 00, 01, 10, or 11 for phase 0,1,2,3 (a,b,c,d) and “bits 4–10” represent frames “000” through “127”.

My hypothesis was that his address was causing data to be sent in a different phase by the test transmitter. Our code was currently only decoding Phase A. We had not yet observed the test transmitter sending data in a different phase, so we only decoded one phase by default until we learned about a problem.

The time had finally come to improve that code.

Adding a Failing Test

Our unit test suite for this demonstration is CMocka. We have an existing test suite, so we simply need to plug in a new test for this case.

Luckily, I was given a raw 2-FSK payload which demonstrated the failure. If I didn’t have one, I would set up the test transmitter using the failing address, reproduce the issue, and then capture the raw bytes received from the bus.

Our unit test suite is designed to work without the hardware, so we’ll create a C array representing the raw bytes received from the radio:

const uint8_t fsk2_3200_short_addr_phase_b[FLEX_WORKING_PAYLOAD_SIZE] = {
    0x12, 0x7b, 0x89, 0xdd, 0xcc, 0x88, 0xc9, 0xdd, 0x98, 
    0x88, 0xd9, 0xdd, 0x9c, 0x88, 0x89, 0xdd, 0x88, 0x88,
    0x89, 0xdd, 0x98, 0x88, 0x99, 0xdd, 0xdc, 0x88, 0x9d, 
    0xdd, 0x98, 0x88, 0x89, 0xdd, 0x9c, 0x88, 0x8d, 0xdd, 
    0x88, 0x88, 0x89, 0xdd, 0x9c, 0x88, 0x9d, 0xdd, 0xcc,
    // ... lots more bytes
};

This buffer will be consumed by our test case.

We want our initial test case to fail, so we need to check the client’s failure mode. Looking at the log, we see a failure to decode the block information word (“BIW”):

Mode identified: 2FSK, 3200bps
Converting to blocks for 3200bps
Raw BIW: 0xffffffff, reversed: 0xffffffff
Unable to validate/repair BIW for flex frame. Discarding frame.

We’ll create an initial test case which uses our input data buffer and checks for expected BIW values:

static void fsk2_3200_phaseb_test(void** state)
{
    flex_state_t current_state = FLEX_STATE_2FSK_RX;

    memcpy(working_raw_payload, fsk2_3200_short_addr_phase_b, 
        FLEX_WORKING_PAYLOAD_SIZE);

    current_state =
        interpret_message(current_state, &payload, 
            working_raw_payload, 
            FLEX_WORKING_PAYLOAD_SIZE);

    assert_int_equal(current_state, FLEX_STATE_PREPARE_FOR_RX);

    // Check BIW against known good values
    assert_int_equal(payload.frame.biw.priority, 1);
    assert_int_equal(payload.frame.biw.carry_on, 0);
    assert_int_equal(payload.frame.biw.eob_info, 0);
    assert_int_equal(payload.frame.biw.address_start, 1);
    assert_int_equal(payload.frame.biw.vector_start, 2);
}

CMocka doesn’t support automatic test registration, so we need to update our test list:

int fsk2_3200_tests(void)
{
    const struct CMUnitTest fsk2_3200_test_list[] = {
        cmocka_unit_test_setup_teardown(fsk2_3200_alpha_test, 
            testSetup, testTeardown),
        cmocka_unit_test_setup_teardown(fsk2_3200_phaseb_test, 
            testSetup, testTeardown),
    };

    return cmocka_run_group_tests(fsk2_3200_test_list, NULL, NULL);
}

Before we do anything else, we want to confirm that the test fails. Luckily it does:

[==========] Running 2 test(s).
[ RUN      ] fsk2_3200_test
[       OK ] fsk2_3200_test
[ RUN      ] fsk2_3200_phaseb_test
[  ERROR   ] --- 0 != 0x2
[   LINE   ] --- ../test/state_machine/fsk2_3200_tests.c:68: error: Failure!
[  FAILED  ] fsk2_3200_phaseb_test
[==========] 2 test(s) run.
[  PASSED  ] 1 test(s).
[  FAILED  ] 1 test(s), listed below:
[  FAILED  ] fsk2_3200_phaseb_test

Turning on debug output confirms that we get the same message:

Converting to blocks for 3200bps
Raw BIW: 0xffffffff, reversed: 0xffffffff
Unable to validate/repair BIW for flex frame. Discarding frame.
Error processing BIW. Returning to wait state
[  ERROR   ] --- 0 != 0x1
[   LINE   ] --- ../test/state_machine/fsk2_3200_tests.c:68: error: Failure!
[  FAILED  ] fsk2_3200_phaseb_test

Now that we’ve confirmed the failure, we can begin to work on the problem.

Finding the Problem

I generated an initial hypothesis, which I shared above:

My hypothesis was that his address was causing data to be sent in a different phase by the test transmitter. Our code was currently only decoding Phase A. We had not yet observed the test transmitter sending data in a different phase, so we only decoded one phase by default until we learned about a problem.

Because I have a hypothesis, I know where to begin my search: the location where I’m selecting the block to decode.

The current logic just decodes one phase of the payload, and then returns:

convert_to_blocks(&payload[offset], len, flex_payload->mode, 
    &flex_payload->frame);
validate_blocks(&flex_payload->frame);

// Next, process the block information word
uint32_t biw_raw = *(const uint32_t*)(&(flex_payload->frame.blocks[0].word[0]));
bool result = process_biw(biw_raw, &flex_payload->frame);
if(!result)
{
    debug_printf("Error processing BIW. Returning to wait state
");
    return FLEX_STATE_PREPARE_FOR_RX;
}

parse_for_additional_biws(&flex_payload->frame);
find_all_non_instruction_vectors(&flex_payload->frame);

I’m building a generic decoder at the moment, so I will need to adjust this to address all blocks. Before I work on a complicated change, I want to confirm that this is actually the problematic section of the code.

My plan is to change the convert_to_blocks function to pull from phase B. I will expect the new test case to pass and other test cases to fail.

Amusingly, there’s a relevant TODO at the top of the function:

// TODO: we need to support phase A, B, C, D. 
// Right now we just grab phase A.
void convert_to_blocks(const uint8_t* payload, size_t len, 
    flex_mode_t mode, flex_frame_t* frame)

In the code below, I added a new phase variable, which is set to 0. In the 2-FSK 3200bps block, we set phase to 1 for testing. We then pass phase to get_flex_word as a new argument. Changes made for this test scenario are commented below.

void convert_to_blocks(const uint8_t* payload, size_t len, flex_mode_t mode, flex_frame_t* frame)
{
    assert(len >= (11 * 8 * 4));
    unsigned bytes_per_block;
    uint8_t phase = 0; // <---- New debug variable

    switch(mode)
    {
        case FLEX_MODE_2FSK_1600BPS:
            debug_printf("Converting to blocks for 1600bps
");
            bytes_per_block = BYTES_TO_ADVANCE_PER_BLOCK_1600BPS;
            break;
        case FLEX_MODE_2FSK_3200BPS:
        case FLEX_MODE_4FSK_3200BPS:
            debug_printf("Converting to blocks for 3200bps
");
            phase = 1; // <---- Hardcoded test case here
            bytes_per_block = BYTES_TO_ADVANCE_PER_BLOCK_3200BPS;
            break;
        case FLEX_MODE_4FSK_6400BPS:
            debug_printf("Converting to blocks for 6400bps
");
            bytes_per_block = BYTES_TO_ADVANCE_PER_BLOCK_6400BPS;
            break;
        default:
            assert(0);
            break;
    }

    for(int block_counter = 0; block_counter < 11; block_counter++)
    {
        for(int word_counter = 0; word_counter < 8; word_counter++)
        {
            frame->blocks[block_counter].word[word_counter] =
                get_flex_word(&(payload[block_counter * bytes_per_block]), 
                    word_counter, mode, phase);
                // ^ phase is a new argument in this function
        }
    }
}

The get_flex_word prototype needs updated:

uint32_t get_flex_word(const uint8_t* payload, uint8_t word_position, 
    flex_mode_t mode, uint8_t phase);

Then the implementation needs to be updated to handle the phase information. When multiple phases are present in FLEX data, the blocks are interleaved. Bit 0 corresponds to Phase 0 / block 0 / bit 0, Bit 1 corresponds to Phase 1 / block 0 / bit 0, Bit 3 corresponds to Phase 0 / block 0 / bit 1, etc.

We need to adjust our logic to handle phases in our math. The new line is commented below. Trust me, this works with the bitwise logic.

uint32_t get_flex_word(const uint8_t* payload, uint8_t word_position, flex_mode_t mode, uint8_t phase)
{
    uint32_t word = 0;
    uint8_t bit_mask;
    uint8_t advancement;

    assert(word_position < 8);
    
    // NEW LINE - adjust word position logic based on phase
    word_position = word_position | (phase << 3);

    switch(mode)
    {
        case FLEX_MODE_2FSK_1600BPS:
            bit_mask = 0x80 >> word_position;
            advancement = 1;
            break;
        case FLEX_MODE_2FSK_3200BPS:
        case FLEX_MODE_4FSK_3200BPS:
            // 2 Blocks are interleaved so this math makes sense 🙂
            word_position = (word_position << 1) | ((word_position >> 3) & 1);
            if(word_position & 8)
            {
                payload++;
            }
            bit_mask = 0x80 >> (word_position & 7);
            advancement = 2;
            break;
        case FLEX_MODE_4FSK_6400BPS:
            // 4 Blocks are interleaved so this math makes sense 🙂
            word_position = (word_position << 2) | ((word_position >> 3) & 3);
            payload += ((word_position >> 3) & 3);
            bit_mask = 0x80 >> (word_position & 7);
            advancement = 4;
            break;
        default:
            assert(0); // Invalid mode
    };

    for(unsigned i = 0; i < 32; i++)
    {
        word <<= 1;
        if(*payload & bit_mask)
        {
            word |= 1;
        }
        payload += advancement;
    }

    return word;
}

OK! We’ve hacked our code, now we want to confirm the hypothesis. I’m expecting that the new test will pass, while the old test will fail.

That’s what happens:

[==========] Running 2 test(s).
[ RUN      ] fsk2_3200_test
Interpreting 2-FSK Message (len: 706)
Converting to blocks for 3200bps
Raw BIW: 0xffffffff, reversed: 0xffffffff
Unable to validate/repair BIW for flex frame. Discarding frame.
Error processing BIW. Returning to wait state
[  ERROR   ] --- 0 != 0x2
[   LINE   ] --- ../test/state_machine/fsk2_3200_tests.c:49: error: Failure!
[  FAILED  ] fsk2_3200_test
[ RUN      ] fsk2_3200_phaseb_test
Interpreting 2-FSK Message (len: 707)
Converting to blocks for 3200bps
Raw BIW: 0x68100633, reversed: 0xcc600816
Decoded BIW: Priority=1, CarryOn=0, VectorStart=2, AddressStart=1, EOB=0, Collapse=0
No additional BIWs detected
Address raw word: 0x1c7d19a0, reversed: 0x598be38
Decoded short address: 1588792
[To: 1588792] [@: 0] (fmt: 0) (len: 4), radio: 0
Message: [5
No enqueue function is registered, dropping message
[       OK ] fsk2_3200_phaseb_test
[==========] 2 test(s) run.
[  PASSED  ] 1 test(s).
[  FAILED  ] 1 test(s), listed below:
[  FAILED  ] fsk2_3200_test

Now we can work on the real fix.

Making a Fix

We’ve verified that our hypothesis is correct by confirming that a quick-and-dirty change gets the failing test to pass (and that the previously passing test fails, as expected). Now we can safely invest time in a solution that works for all cases.

We previously added a local variable called phase to the convert_to_blocks function. We need to update this function prototype to take in phase as an argument (and to delete that TODO comment!):

void convert_to_blocks(const uint8_t* payload, size_t len, flex_mode_t mode, 
    flex_frame_t* frame, uint8_t phase)

We’re also going to delete this hardcoded line (added for testing purposes) from convert_to_blocks:

phase = 1;

To make the code robust, we’re going to add assert checks to the switch statement inside convert_to_blocks:

switch(mode)
{
    case FLEX_MODE_2FSK_1600BPS:
        debug_printf("Converting to blocks for 1600bps
");
        bytes_per_block = BYTES_TO_ADVANCE_PER_BLOCK_1600BPS;
        // 2-FSK 1600bps only has one phase per frame
        assert(phase < 1); 
        break;
    case FLEX_MODE_2FSK_3200BPS:
    case FLEX_MODE_4FSK_3200BPS:
        debug_printf("Converting to blocks for 3200bps
");
        bytes_per_block = BYTES_TO_ADVANCE_PER_BLOCK_3200BPS;
        // 3200bps modes have two phases per frame
        assert(phase < 2);
        break;
    case FLEX_MODE_4FSK_6400BPS:
        debug_printf("Converting to blocks for 6400bps
");
        bytes_per_block = BYTES_TO_ADVANCE_PER_BLOCK_6400BPS;
        // 6400bps mode has four phases per frame
        assert(phase < 4); 
        break;
    default:
        assert(0);
        break;
}

We don’t need to modify the get_flex_word logic, that change was shippable.

Next, we’ll update the primary logic which decodes the FLEX frame. Based on the data mode, we’re going to iterate through each phase. If the BIW is 0xffffffff, we know there is no data in that phase, and we continue to the next. All phases with valid data will be decoded.

As a refresher, this is the code we need to modify:

convert_to_blocks(&payload[offset], len, flex_payload->mode, &flex_payload->frame);
validate_blocks(&flex_payload->frame);

// Next, process the block information word
uint32_t biw_raw = *(const uint32_t*)(&(flex_payload->frame.blocks[0].word[0]));
bool result = process_biw(biw_raw, &flex_payload->frame);
if(!result)
{
    debug_printf("Error processing BIW. Returning to wait state
");
    return FLEX_STATE_PREPARE_FOR_RX;
}

parse_for_additional_biws(&flex_payload->frame);
find_all_non_instruction_vectors(&flex_payload->frame);

First, we must set the number of phases to attempt to decode based on the FLEX mode:

uint8_t num_phases = 0;
switch(flex_payload->mode)
{
    case FLEX_MODE_2FSK_1600BPS:
        num_phases = 1;
        break;
    case FLEX_MODE_2FSK_3200BPS:
    case FLEX_MODE_4FSK_3200BPS:
        num_phases = 2;
        break;
    case FLEX_MODE_4FSK_6400BPS:
        num_phases = 4;
        break;
    default:
        assert(0);
}

We’ll need to iterate through the block decoding code num_phases times. If there is an error processing the BIW for a given phase, we’ll note that it’s invalid for the debug log, then we continue to the next phase.

for(uint8_t phase = 0; phase < num_phases; phase++)
{
    convert_to_blocks(&payload[offset], len, flex_payload->mode, 
            &flex_payload->frame, phase);
    validate_blocks(&flex_payload->frame);

    // Next, process the block information word
    uint32_t biw_raw = *(const uint32_t*)(&(flex_payload->frame.blocks[0].word[0]));
    bool result = process_biw(biw_raw, &flex_payload->frame);
    if(!result)
    {
        debug_printf("Invalid BIW, skipping phase.
");
        continue;
    }

    parse_for_additional_biws(&flex_payload->frame);
    find_all_non_instruction_vectors(&flex_payload->frame);
}

The only concern I have at this point is whether our tests will still pass. We’re now processing multiple phases in one pass: what happens when an invalid BIW is detected? Will the BIW checks in our tests fail if the last phase has an invalid BIW?

Checking the process_biw function above, I see that the flex_payload->frame entries are only updated when there’s a valid BIW, so we are OK in this scenario.

bool process_biw(uint32_t biw_raw, flex_frame_t* frame)
{
    flex_val_result_t result = validateWord(&biw_raw, 
        (TASK_VALIDATE_CHECKSUM | TASK_REPAIR_2));
    if(result == VALIDATE_FAIL)
     {
        return false;
    }

    biw_raw >>= 6;
    frame->biw.sys_frame_collapse = 
        REVERSE_BITS_8((uint8_t)biw_raw) & 0x07;
    biw_raw >>= 2;
    frame->biw.carry_on = REVERSE_BITS_8((uint8_t)biw_raw) & 0x03;
    biw_raw >>= 6;
    frame->biw.vector_start = REVERSE_BITS_8((uint8_t)biw_raw) & 0x3F;
    biw_raw >>= 2;
    frame->biw.eob_info = REVERSE_BITS_8((uint8_t)biw_raw) & 0x03;
    frame->biw.address_start = frame->biw.eob_info + 1;
    biw_raw >>= 4;
    frame->biw.priority = REVERSE_BITS_8((uint8_t)biw_raw) & 0x0F;

    return true;
}

Now we’re ready to test the fix!

Verifying the Fix

We verified our hypothesis before by inserting a small change and proving that it corrected our failing test case. With the proper fix in place, we expect that all test cases will now pass. And they do (along with about 100 other tests not shown here).

[==========] Running 2 test(s).
[ RUN      ] fsk2_3200_test
[       OK ] fsk2_3200_test
[ RUN      ] fsk2_3200_phaseb_test
[       OK ] fsk2_3200_phaseb_test
[==========] 2 test(s) run.
[  PASSED  ] 2 test(s).

Release

The final step is to release the code to the client.

At this point, you might expect me to run this code on the hardware before committing it and releasing it to the client. I definitely recommend testing the code on-target before making a customer-facing release. Ideally, your project’s CI process will include a hardware-in-the-loop testing step. Ideally, your team also has a QA test suite and staged firmware update rollout so you won’t brick everyone’s devices with one bad build. These are excellent practices that should be continued.

But in this demonstration, I’m not going to test the code on hardware. I’m confident in the test suite we’ve built. I’ve used real radio data captured from a real radio. I’m going to take a chance and show you what the client’s feedback is. You’ll just have to trust that I played by the rules.

Feedback

I released the code for the client to test. Here was the email:

The issue has been addressed. You will now see all phases being decoded for received FLEX frames. If there is no data received within a given phase, you will see an “Invalid BIW, skipping phase” message.

I also included sample output generated from the test suite’s debug output.

The result: our client reported that the software was working correctly when they tested it. No complaints!

Takeaways

Thanks to my off-target testing setup, I was able to correct a problem my customer was seeing without using ANY HARDWARE.

If you read the original article, I used a testing setup that took me only fifteen minutes to put together. It doesn’t take much investment to start earning dividends from your test suite.

Are you taking advantage of these techniques for your projects? If not, why?

Further Reading

Share Your Thoughts

This site uses Akismet to reduce spam. Learn how your comment data is processed.