C++ Troubleshooting Challenge

DavidZemon · 2014-10-06 20:23

I've attached two SimpleIDE projects with the relevant code.

I've created a class that should be able to safely print from multiple cogs. Sometimes, it even works! The problems is, I can't figure out why it doesn't work all of the time.

Technical details explained:

UART and its children are the hardware drivers.
SimplexUART is the most basic UART concrete class capable of transmitting from a single cog. It is not thread safe and can not be used from multiple cogs.
SharedSimplexUART is still not thread safe, but it can be used from multiple cogs so long as the user ensures two cogs do not print simultaneously.
Printer is a class that contains formatting functionality such as put_int, put_hex, and printf. Just a clean way to keep those big functions out of the UART classes.
- A pointer to a PrintCapable class is required (UART implements PrintCapable) by the constructor and saved as a member variable. That member is then called on to do the printing
SynchronousPrinter wraps all of its methods with locks so that it is thread-safe.

Project 1: Hello_Demo
Hello_Demo works great! It's just a basic use of Printer and SimplexUART that I created to compare all the different "Hello, world!" programs. Pretty cool.... except that it doesn't work when compiled within PropWare! I was fully expecting to come here to the forums and say "Why don't either of these projects work!?"... but when I ran it outside of the PropWare build system, it works. I have no idea why.

The problem I have within the PropWare build system is Printer::_printf. It is defined as virtual currently (so that I can override it and use locks in SynchronousPrinter) and is the deepest root of the problem that I can find. If I remove virtual, Hello_Demo works again. If I change the call in Printer::printf from

this->_printf( /* args */ );

to

Printer::_printf( /* args */);

then it works (even with virtual still in the signature).
I can't imagine why this works in the simple case of a standalone project but not PropWare.

Project 2: SynchronousPrinter_Demo
Much simpler problem to describe. It isn't thread safe. Not sure why

Any help is appreciated! I've tried to make it as easy as possible to help me debug, but even still I know it is quite complex with all of the files. Let me know if there's something else I can do to make it easier.

David

SRLM · 2014-10-06 22:05

Where's the printer code? I don't see it in the downloads. Also, the files in the zips need to have their permissions edited.

DavidZemon · 2014-10-07 05:11

SRLM wrote: »

Where's the printer code? I don't see it in the downloads. Also, the files in the zips need to have their permissions edited.

Thanks. I was too zonked to even think about checking the zips before passing out. A PropWare folder has been added to each zip with only the relavent PropWare headers.

David

DavidZemon · 2014-10-07 05:29

And a new branch was created while I work out these bugs:
https://github.com/DavidZemon/PropWare/tree/printer

SRLM · 2014-10-07 10:56

Have you tried it with just a single cog? I reduced the program down to this:

// Includes
#include <PropWare/PropWare.h>
#include <PropWare/printer.h>
#include <PropWare/uart/sharedsimplexuart.h>

PropWare::SharedSimplexUART  g_sharedUart(
    PropWare::UART::PARALLAX_STANDARD_TX);
PropWare::SynchronousPrinter syncOut(&g_sharedUart);

int main () {
    while (1) {
        syncOut.put_char('A');
        waitcnt(CLKFREQ + CNT);
    }
    return 0;
}

And I get gibberish output:

AI&#65533;&#65533;&#65533;

          B 
                  &#65533;D0b&#65533;
                          @D&#65533;&#65533;F&#65533;! A&#65533;CA$A

Watching the output, it looks like the serial driver is adding on extra bits at the end: the output comes in 1 second bursts, with the A followed by some number of bad bits.

DavidZemon · 2014-10-07 11:04

SRLM wrote: »

Have you tried it with just a single cog? I reduced the program down to this:

Watching the output, it looks like the serial driver is adding on extra bits at the end: the output comes in 1 second bursts, with the A followed by some number of bad bits.

I haven't. That's very odd. I'll see if I can figure out why my scope wasn't working last night and give it another try this evening with just one cog.

DavidZemon · 2014-10-07 15:28

Well isn't that weird! It's working perfectly for me! After copying and pasting your code exactly as you wrote it there into my SimpleIDE SynchronousPrinter_Demo project, it works flawlessly (running via the terminal button in SimpleIDE and checked with my Saleae from Pin 0)

As a side note... I'm feeling quite dumb. I'm scoping my board like so:

And nothing shows up. If I change the UART pin to P0 (and of course move the probe to the first pin), it works. Does the Quickstart somehow intercept P30 and keep me from reading it at the header?

DavidZemon · 2014-10-07 20:10

Out of desperation, I've moved the member variable, m_lock, into Printer instead of SynchronousPrinter. Printer's constructor initializes it to -1 and then printf only tries to use the lock if it's not -1. This removes the need for _printf - completely eradicating any problems with the Hello_Demo app.

Unfortunately, that didn't help at all with my synchronous issue. Three nights in a row now I've been banging my head against the wall trying to get this to work and I can't seem to figure it out where the issue lies. :frown:

A little more info:
Going to put_uint(cog) instead of printf("Hello from cog %u", cog) removes any issues. It seems to work fine when I do that. Using puts("Hello") works too (so long as "Hello" is a literal and not a local variable).

DavidZemon · 2014-10-09 20:00

Fixed a few bugs, but still no luck.

Fixed:
* printf was interruptable
* lock was not cleared upon instantiation
* lock can now be checked and refreshed

I've uploaded a binary distribution of the printer branch.

David

kuroneko · 2014-10-12 00:03

Based on the code attached to the top post the following changes should be applied to SynchronousPrinter_Demo.cpp:

const uint16_t         STACK_SIZE = [COLOR="#FF0000"]24[/COLOR];
static uint32_t        cog_stack[COLOR="#FF0000"][COGS][STACK_SIZE][/COLOR];

...

        cog = (int8_t) _start_cog_thread(cog_stack[n] [COLOR="#FF0000"]/* + STACK_SIZE */[/COLOR], do_toggle, [COLOR="#FF8C00"]NULL[/COLOR], &thread_data);

The parameter has been changed to NULL as the cog ID can be determined by a function call.

Also, IIRC the quickstart board doesn't have a pull-up on pin 30 so the shared UART class - when releasing its pin driver - will cause the pin to float, NG (evidently, even if I only use one cog to drive the pin I get ghost characters within the gaps). To test functionality I kept the dira setup and sent data from all cogs inverted (idle low) to an unrelated pin which is then routed through a feedback counter to pin 30.

Note, for some reason the sequences "\n\r" and "\r\n" show different behaviour in the SimpleIDE terminal. The latter works for me.

DavidZemon · 2014-10-12 07:33

I've fixed all of those issues in my latest version and still no luck

I noticed the "\n\r" and "\r\n thing too and, after looking at the Simple sources, figured out they use "\r\n" so I did changed it around. As for stack size, I'm using 128 longs so that's not a problem. Interesting that it still works when you comment out the `+ STACK_SIZE` lol.

I did just notice that

cog_stack[n] + STACK_SIZE

isn't *quite* what I wanted. so i've changed it to

cog_stack[n] + sizeof(cog_stack[n])

but it didn't help any.

I've also applied a pull-up resistor to my board with no luck

DavidZemon · 2014-10-12 07:43

ALL THIS TIME!!!

And I never initialized wait_time. Though adding that initialization fixes the supposed deadlock problem that I thought I was having, it's still not 100% on my machine. I am repeatedly getting:

Toggle COG 1 Started
Toggle COG 2 Started
Toggle COG 3 Started
Toggle COG 4 Started
Toggle COG 5 Started
Toggle COG 6 Started
Toggle COG 7 Started
Hello from cog 0
Hello from cog 2412
Hello from cog 2412
Hello from cog 2412
Hello from cog 2412
Hello from cog 2412
Hello from cog 2412
Hello from cog 7

And I've seen this "2412" time and time again. Been getting that for a long time. No idea why. This copy of the demo code can be found here. And here for the entire commit.

__Edit__

If I disable some of the cogs (for instance, but wrapping the entire `run_cog` function in

if (1 == cogid() || 2 == cogid() || 3 == cogid()) {
  // the stuffs
}

then cog 3 works and 1 and 2 print 2448. If I enable only cogs 1 and 2, then 2 works and 1 prints 2436. Enabling only cog 1 makes both 0 and 1 work perfectly.

kuroneko · 2014-10-12 16:40

The call to _start_cog_thread only takes cog_stack[n] as the first parameter. And your cog_stack declaration is still wrong (n[a][noparse][/noparse] is not necessarily the same as n[noparse][/noparse][a]).

/**
 * @file    Hello_Demo.cpp
 *
 * @author  David Zemon
 */

// Includes
#include <PropWare/PropWare.h>
#include <PropWare/printer.h>
#include <PropWare/uart/sharedsimplexuart.h>

const PropWare::SharedSimplexUART  g_sharedUart(PropWare::UART::PARALLAX_STANDARD_TX);
const PropWare::SynchronousPrinter syncOut(&g_sharedUart);

const uint16_t  COGS       = 8;
const uint16_t  STACK_SIZE = [COLOR="#FF0000"]24[/COLOR];
static uint32_t [COLOR="#FF0000"]cog_stack[COGS][STACK_SIZE][/COLOR];
static _thread_state_t thread_data;

volatile uint32_t wait_time = 1000 * MILLISECOND;
volatile uint32_t startCnt  = 0;

static void do_toggle(void *arg) {
    // wait for start signal from main cog
    while (!startCnt);

    uint32_t nextCnt = wait_time + startCnt;
    for (;;) {
        syncOut.printf("Hello from cog %u\r\n", cogid());
        nextCnt = waitcnt2(nextCnt, wait_time);
    }
}

int main(int argc, char *argv[]) {
    waitcnt(CLKFREQ*3 + CNT);

    for (int n = 1; n < COGS; n++) {
        int cog = _start_cog_thread([COLOR="#FF0000"]cog_stack[n][/COLOR], do_toggle, NULL, &thread_data);
        syncOut.printf("Toggle COG %d Started %d\r\n", cog, cog_stack[n]);
    }

    uint32_t nextCnt = wait_time + (startCnt = CNT|1);
    for (;;) {
        syncOut.printf("Hello from cog %u\r\n", cogid());
        nextCnt = waitcnt2(nextCnt, wait_time);
    }
    return 0;
}

DavidZemon · 2014-10-12 17:49

kuroneko wrote: »

The call to _start_cog_thread only takes cog_stack[n] as the first parameter. And your cog_stack declaration is still wrong (n[a][noparse][/noparse] is not necessarily the same as n[noparse][/noparse][a]).

/**
 * @file    Hello_Demo.cpp
 *
 * @author  David Zemon
 */

// Includes
#include <PropWare/PropWare.h>
#include <PropWare/printer.h>
#include <PropWare/uart/sharedsimplexuart.h>

const PropWare::SharedSimplexUART  g_sharedUart(PropWare::UART::PARALLAX_STANDARD_TX);
const PropWare::SynchronousPrinter syncOut(&g_sharedUart);

const uint16_t  COGS       = 8;
const uint16_t  STACK_SIZE = [COLOR=#FF0000]24[/COLOR];
static uint32_t [COLOR=#FF0000]cog_stack[COGS][STACK_SIZE][/COLOR];
static _thread_state_t thread_data;

volatile uint32_t wait_time = 1000 * MILLISECOND;
volatile uint32_t startCnt  = 0;

static void do_toggle(void *arg) {
    // wait for start signal from main cog
    while (!startCnt);

    uint32_t nextCnt = wait_time + startCnt;
    for (;;) {
        syncOut.printf("Hello from cog %u\r\n", cogid());
        nextCnt = waitcnt2(nextCnt, wait_time);
    }
}

int main(int argc, char *argv[]) {
    waitcnt(CLKFREQ*3 + CNT);

    for (int n = 1; n < COGS; n++) {
        int cog = _start_cog_thread([COLOR=#FF0000]cog_stack[n][/COLOR], do_toggle, NULL, &thread_data);
        syncOut.printf("Toggle COG %d Started %d\r\n", cog, cog_stack[n]);
    }

    uint32_t nextCnt = wait_time + (startCnt = CNT|1);
    for (;;) {
        syncOut.printf("Hello from cog %u\r\n", cogid());
        nextCnt = waitcnt2(nextCnt, wait_time);
    }
    return 0;
}

_start_cog_thread asks for the top of the stack though, not the bottom. and I did try it both ways - it actually made no difference lol

kuroneko · 2014-10-12 18:02

SwimDude0614 wrote: »

_start_cog_thread asks for the top of the stack though, not the bottom. and I did try it both ways - it actually made no difference lol

Well, cog_stack[n] works for me, if I pass the top of the stack (base+size) it doesn't. Odd.

kuroneko · 2014-10-12 18:46

I confirmed the TOS requirement and it turns out that the stack needs to be a bit larger than 24 longs. Revised code below:

/**
 * @file    Hello_Demo.cpp
 *
 * @author  David Zemon
 */

// Includes
#include <PropWare/PropWare.h>
#include <PropWare/printer.h>
#include <PropWare/uart/sharedsimplexuart.h>

const PropWare::SharedSimplexUART  g_sharedUart(PropWare::UART::PARALLAX_STANDARD_TX);
const PropWare::SynchronousPrinter syncOut(&g_sharedUart);

const uint16_t  COGS       = 8;
const uint16_t  STACK_SIZE = [COLOR="#FF0000"]42[/COLOR];
static uint32_t [COLOR="#FF0000"]cog_stack[COGS][STACK_SIZE][/COLOR];
static _thread_state_t thread_data;

volatile uint32_t wait_time = 1000 * MILLISECOND;
volatile uint32_t startCnt  = 0;

static void do_toggle(void *arg) {
    // wait for start signal from main cog
    while (!startCnt);

    uint32_t nextCnt = wait_time + startCnt;
    for (int i = 0; i < 10; i++) {
        syncOut.printf("Hello from cog %u\r\n", cogid());
        nextCnt = waitcnt2(nextCnt, wait_time);
    }
}

int main(int argc, char *argv[]) {
    waitcnt(CLKFREQ*3 + CNT);

    for (int n = 1; n < COGS; n++) {
        int cog = _start_cog_thread([COLOR="#FF0000"]&cog_stack[n][STACK_SIZE][/COLOR], do_toggle, NULL, &thread_data);
        syncOut.printf("Toggle COG %d Started %d %d\r\n", cog, cog_stack[n], sizeof(cog_stack[n]));
    }

    uint32_t nextCnt = wait_time + (startCnt = CNT|1);
    for (;;) {
        syncOut.printf("Hello from cog %u\r\n", cogid());
        nextCnt = waitcnt2(nextCnt, wait_time);
    }
    return 0;
}

FWIW, this is with -Os and pruning enabled.

David Betz · 2014-10-12 19:40

kuroneko wrote: »

I confirmed the TOS requirement and it turns out that the stack needs to be a bit larger than 24 longs. Revised code below:

/**
 * @file    Hello_Demo.cpp
 *
 * @author  David Zemon
 */

// Includes
#include <PropWare/PropWare.h>
#include <PropWare/printer.h>
#include <PropWare/uart/sharedsimplexuart.h>

const PropWare::SharedSimplexUART  g_sharedUart(PropWare::UART::PARALLAX_STANDARD_TX);
const PropWare::SynchronousPrinter syncOut(&g_sharedUart);

const uint16_t  COGS       = 8;
const uint16_t  STACK_SIZE = [COLOR="#FF0000"]42[/COLOR];
static uint32_t [COLOR="#FF0000"]cog_stack[COGS][STACK_SIZE][/COLOR];
static _thread_state_t thread_data;

volatile uint32_t wait_time = 1000 * MILLISECOND;
volatile uint32_t startCnt  = 0;

static void do_toggle(void *arg) {
    // wait for start signal from main cog
    while (!startCnt);

    uint32_t nextCnt = wait_time + startCnt;
    for (int i = 0; i < 10; i++) {
        syncOut.printf("Hello from cog %u\r\n", cogid());
        nextCnt = waitcnt2(nextCnt, wait_time);
    }
}

int main(int argc, char *argv[]) {
    waitcnt(CLKFREQ*3 + CNT);

    for (int n = 1; n < COGS; n++) {
        int cog = _start_cog_thread([COLOR="#FF0000"]&cog_stack[n][STACK_SIZE][/COLOR], do_toggle, NULL, &thread_data);
        syncOut.printf("Toggle COG %d Started %d %d\r\n", cog, cog_stack[n], sizeof(cog_stack[n]));
    }

    uint32_t nextCnt = wait_time + (startCnt = CNT|1);
    for (;;) {
        syncOut.printf("Hello from cog %u\r\n", cogid());
        nextCnt = waitcnt2(nextCnt, wait_time);
    }
    return 0;
}

FWIW, this is with -Os and pruning enabled.

You definitely need to specify the address of the top of the stack not the bottom. The stack grows from high memory down to low memory in PropGCC so if you were going to pass the address of the bottom of the stack you'd also have to pass the size.

DavidZemon · 2014-12-16 19:15

Well this issue has taken two full months of time and a complete re-write of both the Printer and SynchronousPrinter classes... but it's working! And SynchronousPrinter has a nice big warning at the top about the possible hardware changes that go along with synchronous printing.

But hey! Look at this! Those of us using PropGCC now have the ability to easily log as much information as we want, whenever we want, from any and all cogs we want! I wish I had this a year ago.

C++ Troubleshooting Challenge

Comments