System dies after several days - system tick problem?

[steved]

I have several identical 32F051 boards running the same code, but with configuration options that affect the number of processor tasks. There are two tasks managing serial ports, plus a couple of other fairly busy tasks using the two I2C ports, and some tasks with less activity. I have two boards running concurrently; the one where just one serial port is in use lasted a week or more, while the one where both serial ports are in use lasts a lesser time; typically 12-24 hours except when I'm watching it! I've finally managed to catch a lockup with the emulator connected after three days!

Code is running in tickless mode:

Code: Select all

#define CH_CFG_ST_FREQUENCY                 10000
#define CH_CFG_ST_TIMEDELTA                 2
#define CH_CFG_TIME_QUANTUM                 0

I have managed to observe the following:
1. The code is still running - no crashes or stack overflows.
2. Most threads are sleeping; a couple are waiting for events (one will never get triggered; the other is timer-driven):

List of threads

Thread_List.png (18.75 KiB) Viewed 4163 times

3. Interrupts still work - one serial port is still receiving messages OK, and sets a semaphore to trigger processing; however they aren't processed because the processing thread is somewhere else. (Normally the processing thread is in a loop waiting on this semaphore).
4. The thread which initiates transactions on the second serial port isn't looping as it should; presumably because its sleeping somewhere.
5. It appears that Timer 2, which generates the system tick/timing, isn't triggering. The counter itself is still going, but a breakpoint on its ISR is never hit, and the register contents look as if timer interrupts are disabled:

Timer 2 register values

Systick_Timer_Values.png (52.36 KiB) Viewed 4163 times

I don't think its a hardware problem; mostly because the problem is apparent on several boards, and also because I'm reasonably certain the same boards ran for longer periods of time when the code was simpler.

Any suggestions on where to go from here in tracking this down? I'll not reset the processor until tomorrow just in case there's more useful information to be gleaned.

[Giovanni]

It looks like that the timer CNT value went past the CCR1 without triggering an interrupt.

Could you try to increase time delta to 3 or 4? it looks like that when planets align (multiple ISRs at the same time probably) then the virtual timers are skipping a beat.

Giovanni

[steved]

it looks like that when planets align (multiple ISRs at the same time probably) then the virtual timers are skipping a beat.

That certainly makes sense - the serial ports are interrupt-driven (not enough DMA controllers) so even at 9600 baud there could be multiple simultaneous/consecutive interrupts from time to time.

Could you try to increase time delta to 3 or 4?

Tried both, and not the expected result! For both values the lockup occurred much sooner - a few minutes, rather than hours/days.

For now I've done two things:
1. I've made sure that the shortest chThdSleepMilliseconds() is 2ms (it was 1ms).
2. I had a couple of loops waiting for a flag:

Code: Select all

      while (serialData[HOST_DATA].txInProgress)
      {
        chThdSleepMilliseconds(1);          // Can do nothing more until message sent
      }

They now wait on semaphores with a timeout - which is the way it should have been coded in the first place.

It looks like that the timer CNT value went past the CCR1 without triggering an interrupt.

Should this happen? Most interrupts are latched until serviced. Or might an ISR have taken so long that interrupt overrun occurred?
Is this a situation which could be picked up and recovered, perhaps with a second timer acting as a long stop? If nothing else it would help flag up the nature of the problem.


I'll also review my ISR code, to see if it can be made shorter. Don't think there's anything excessive, but I guess it all adds up with multiple interrupts flying around.

[Giovanni]

It looks like that the timer CNT value went past the CCR1 without triggering an interrupt.

Should this happen? Most interrupts are latched until serviced. Or might an ISR have taken so long that interrupt overrun occurred?
Is this a situation which could be picked up and recovered, perhaps with a second timer acting as a long stop? If nothing else it would help flag up the nature of the problem.

It does not happen that way. Imagine you are setting a virtual timer, the counter is almost at the time you are going to set, by the time you set the comparator the counter already incremented, the comparison does not happen.
The delta parameter works on that, it is the minimum number of ticks since the deadline you are going to set. The fact that increasing delta makes the problem more frequent makes no sense.

Try disabling the tickless mode and see if the problem disappears (it should).

Giovanni

[steved]

Try disabling the tickless mode and see if the problem disappears (it should).

Tried that, and has been working flawlessly for a couple of hours now. Hopefully a fallback if I can't resolve the problems with tickless mode.

[Giovanni]

I committed few changes to the tickless code and added some assertions, could you check if something is caught?

Giovanni

[steved]

I committed few changes to the tickless code and added some assertions, could you check if something is caught?

Giovanni

Will do; probably be a few days before I can get back to this one.

I did have a look at my code, and found a few one-line functions in ISR callbacks which I've declared as 'inline' now, which might reduce execution time a little (or does the compiler/linker optimiser recognise this situation anyway? I've had to go to -O2 which reduces code size from 64K+1oo bytes to about 40K).

Probably the main overhead in each ISR is that I retrigger a virtual timer each time a character is received. Have started looking at whether this can be done in hardware; USART1 has a suitable function, but not USART2, which is unhelpful.

[steved]

I committed few changes to the tickless code and added some assertions, could you check if something is caught?

Giovanni

No change, I'm afraid.
Only done a quick test, but with my latest code and your latest changes the code still hangs - with delta=3 it took about 4 minutes, with delta=4 it took about 30 seconds! With delta=2 its been running for over 10 minutes so far.
And I've got another board which I set going about 60 hours ago that's still running so far - I'll be happier when its lasted a week.

As before, the hanging appears to be with a long list of virtual timers waiting on thread sleep (although 2 less than there used to be when I first saw the problem).

There are four major sources of activity - two interrupt-driven serial ports, doing about 500cps (half-duplex) each, and two one-wire busses using DS2484 which are running fairly continuously - one on each I2C port. Then four or five more threads which see more limited action.

If the problem is in an ISR, I think I know which one now - I've got a fairly simple state machine on serial receive. Will try and slim this down, although its reasonably tight for what it has to do already.

[Giovanni]

Are assertions/checks/statechecker enabled on the board failing after few minutes?

Giovanni

[steved]

Are assertions/checks/statechecker enabled on the board failing after few minutes?

Giovanni

Yes indeed; never got near enough finished on code to even consider disabling them.

Code: Select all

#define CH_DBG_STATISTICS                   FALSE
#define CH_DBG_SYSTEM_STATE_CHECK           TRUE
#define CH_DBG_ENABLE_CHECKS                TRUE
#define CH_DBG_ENABLE_ASSERTS               TRUE
#define CH_DBG_ENABLE_TRACE                 FALSE
#define CH_DBG_ENABLE_STACK_CHECK           TRUE
#define CH_DBG_FILL_THREADS                 TRUE
#define CH_DBG_THREADS_PROFILING            FALSE