C++ code apparently executing out of sequence

Question

• The code

This is a project on Raspberry Pi using WiringPi. I have the following three member functions of a template class, along with pure virtuals for read() and write(). This base class is then subclassed by more specialized classes that provide the read() and write() function (sample shown down below):

// IChip.hpp (Root abstract class)
class IChip {
    public:
    virtual bool test() noexcept = 0;
};
// End IChip.hpp

// IMemory.hpp (class of interest to the question)
class IMemory: public IChip {
    protected:
    ...
    TAddr m_wordCount;
    TWord m_dataMax;
    // ctor and dtor, and more member fields

    public:
    virtual TWord read(const TAddr addr) const noexcept = 0;
    virtual void write(const TAddr addr, const TWord data) const noexcept = 0;

    // accessors and whatnot ...

    bool march(bool keepGoing = false) noexcept;
    bool checkerboard(bool keepGoing = false) noexcept;

    bool test() noexcept final override;
};
// End IMemory.hpp


// IMemory.cpp
template <typename TAddr, typename TWord>
bool IMemory<TAddr, TWord>::march(bool keepGoing) noexcept {
    bool result = true;
    TAddr i;
    TWord r;
    const uint64_t totalIter = (m_wordCount * 6) - 1;
    uint64_t counter = 0;

    std::cout << "Starting MARCH test." << std::endl;

    for (i = 0; i < m_wordCount; i++) {
        this->write(i, 0);
        std::cout << '\r' << counter << " / " << totalIter << std::flush;
        counter++;
    }

    for (i = 0; i < m_wordCount; i++) {
        r = this->read(i);
        if (r != 0) {
            result = false;
            if (!keepGoing)
                return result;
        }
        this->write(i, m_dataMax);
        std::cout << '\r' << counter << " / " << totalIter << std::flush;
        counter++;
    }

    // 4 more similar loops

    std::cout << std::endl;

    std::cout << "MARCH test done." << std::endl;

    return result;
}

template <typename TAddr, typename TWord>
bool IMemory<TAddr, TWord>::checkerboard(bool keepGoing) noexcept {
    bool result = true;
    TAddr i;
    TWord r;
    TWord curWord;
    const uint64_t totalIter = (m_wordCount * 4) - 1;
    uint64_t counter = 0;

    std::cout << "Starting CHECKERBOARD test." << std::endl;

    curWord = 0;
    for (i = 0; i < m_wordCount; i++) {
        this->write(i, curWord);
        std::cout << '\r' << counter << " / " << totalIter << std::flush;
        counter++;
        curWord = curWord == 0 ? m_dataMax : 0;
    }

    curWord = 0;
    for (i = 0; i < m_wordCount; i++) {
        r = this->read(i);
        if (r != curWord) {
            result = false;
            if (!keepGoing)
                return result;
        }
        std::cout << '\r' << counter << " / " << totalIter << std::flush;
        counter++;
        curWord = curWord == 0 ? m_dataMax : 0;
    }

    // 2 more similar loops ...

    std::cout << std::endl;
    std::cout << "CHECKERBOARD test done." << std::endl;

    return result;
}

template <typename TAddr, typename TWord>
bool IMemory<TAddr, TWord>::test() noexcept {
    bool march_result = this->march();
    bool checkerboard_result = this->checkerboard();
    bool result = march_result && checkerboard_result;

    std::cout << "MARCH: " << (march_result ? "Passed" : "Failed") << std::endl;
    std::cout << "CHECKERBOARD: " << (checkerboard_result ? "Passed" : "Failed") << std::endl;
    return result;
}

// Explicit instantiation
template class IMemory<uint16_t, uint8_t>;
// End IMemory.cpp


// Sample read() and write() from HM62256, a subclass of IMemory<uint16_t, uint8_t>
// These really just bitbang onto / read data from pins with appropriate timings for each chip.
// m_data and m_address are instances of a Bus class, that is just a wrapper around an array of pins, provides bit-banging and reading functionality.

uint8_t HM62256::read(uint16_t addr) const noexcept {
    uint8_t result = 0;

    m_data->setMode(INPUT);
    m_address->write(addr);
    digitalWrite(m_CSPin, LOW);
    digitalWrite(m_OEPin, LOW);
    delayMicroseconds(1);
    result = m_data->read();
    digitalWrite(m_OEPin, HIGH);
    digitalWrite(m_CSPin, HIGH);
    delayMicroseconds(1);
    return result;
}

void HM62256::write(uint16_t addr, uint8_t data) const noexcept {
    digitalWrite(m_OEPin, HIGH);
    delayMicroseconds(1);

    m_address->write(addr);
    delayMicroseconds(1);

    m_data->setMode(OUTPUT);
    m_data->write(data);

    digitalWrite(m_CSPin, LOW);
    digitalWrite(m_WEPin, LOW);
    delayMicroseconds(1);

    digitalWrite(m_WEPin, HIGH);
    digitalWrite(m_CSPin, HIGH);
    delayMicroseconds(1);
}

// main.cpp
void hm62256_test() {
    const uint8_t ADDR_PINS[] = {4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18};
    const uint8_t DATA_PINS[] = {19, 20, 21, 22, 23, 24, 25, 26};
    Chiptools::Memory::HM62256 *device = new Chiptools::Memory::HM62256(ADDR_PINS, DATA_PINS, 2, 3, 27);

    device->setup();
    bool result = device->test();
    std::cout << "Device " << ( result ? "passed all" : "failed some") << " tests." << std::endl;
    delete device;
}

int main(int argc, char *argv[]) {
    wiringPiSetupGpio();
    hm62256_test();
}

• The output

Now when I run this, sometimes it works just fine:

Starting MARCH test.
196607 / 196607
MARCH test done.
Starting CHECKERBOARD test.
131071 / 131071
CHECKERBOARD test done.
MARCH: Passed
CHECKERBOARD: Passed
Device passed all tests.

But randomly I will get this output:

Starting MARCH test.
67113 / 196607Starting CHECKERBOARD test.
33604 / 131071MARCH: Failed
CHECKERBOARD: Failed
Device failed some tests.

• Toolchain info
  • gcc 8.3.0 arm-linux / C++14
  • Cmake 3.16.3
  • No threading.
  • Compiler & Linker flags:

set(CMAKE_CXX_FLAGS_DEBUG "${CMAKE_CXX_FLAGS_DEBUG} -fsanitize=address,leak,undefined")
set(CMAKE_EXE_LINKER_FLAGS "${CMAKE_EXE_LINKER_FLAGS} -fsanitize=address,leak,undefined  -static-libasan")

• The issue and what I tried

I have a couple dozen chips. All of the chips work fine with a TL866ii programmer / tester. This happens with all of these chips. So that rules out the chips as a source of the issue.

Well, at first I thought maybe I'm not flushing the cout stream properly, but AFAIK std::endl does flush the output, so that's not that.

Next, I set a few breakpoints: (A) right before march() returns, (B) right where checkerboard() is called (2nd line in test()), (C) at the 1st line inside checkerboard().

• When output was as expected, breakpoints were hit in this order A, B, C.
• When output was not as expected, breakpoints were hit in this order B, C, A.

What it looks like is happening is, sometimes checkerboard() is called while march() is still running, causing random GPIO output at which point one or both tests fail.

While I'm looking for a solution to this, I'm more interested in some insight on what is happening. I would've thought that since my code is not making use of multithreading, and per my understanding of the C++ standard, statements are executed one by one to completion before the next statement is executed. I'm aware that some compiler implementations do reorder statements for optimization, but AFAIK it should not affect the semantics of my code. I might be wrong as that stuff is way over my head.

Answer 1

This might not be an answer, but it's too long for a comment.

Is A at the return statement after the "March test done" line?

I'm basing the following comments based off this output:

Starting MARCH test.
67113 / 196607Starting CHECKERBOARD test.
33604 / 131071MARCH: Failed
CHECKERBOARD: Failed
Device failed some tests.

What appears to be happening is your MARCH test is failing in the 3rd loop, thus returning early (within the loop). Your Checkerboard test then fails within the 2nd loop, and also returns early. If A is at the position I mentioned, then I think it's just luck or a compiler quirk that that breakpoint is hit.

That is to say, logically, I wouldn't expect breakpoint A to be hit at all when the failure occurs, only for B and C. I think A being hit at the end is probably down to how it program was compiled, and maybe some odd optimizations. Or perhaps where in the assembly the debugger is putting the breakpoint; it might just be on a final instruction that's going to be called anyway. Try putting the breakpoint on the std::cout line before the return and see if it's still hit.

To expand on your comment, this is what I'm seeing in the problem output:

Starting MARCH test.
67113 / 196607 [march() returns early] [checkerboard() starts] Starting CHECKERBOARD test.
33604 / 131071 [checkerboard() returns early] [test() reports results] MARCH: Failed
CHECKERBOARD: Failed
Device failed some tests.

All in all, I think the output will match your expectations if you change your return lines from this:

if (!keepGoing) 
    return result; 

to something like this:

if (!keepGoing) {
    std::cout << std::endl;
    std::cout << "MARCH test failed." << std::endl;
    return result;
}

Which I would expect to produce an output like this:

Starting MARCH test.
67113 / 196607
MARCH test failed
Starting CHECKERBOARD test.
33604 / 131071
CHECKERBOARD test failed
MARCH: Failed
CHECKERBOARD: Failed
Device failed some tests.