Timer interrupt hic-cupping - HELP

[roknjohn]

Trying to set up a 32-bit 10Mhz timer...

I initialized Timer1 like this:volatile unsigned int tmsClock = 0;

void Initialize_Timer_1(void)
{
TMR1L = 0x00;
TMR1H = 0x00;

T1CONbits.T1CKPS0 = 0; // 1:1 prescaler 10Mhz
T1CONbits.T1CKPS1 = 0;
T1CONbits.T1OSCEN = 0; // oscillator disabled
T1CONbits.TMR1CS = 0; // use the internal clock
T1CONbits.RD16 = 1; // timer 1 register operations are done in one 16-bit access

PIE1bits.TMR1IE = 1; // Enable interrupt on overflow
IPR1bits.TMR1IP = 0; // overflow interrupt is low priority
T1CONbits.TMR1ON = 1; // Timer 1 is enablED
}

void Timer_1_Int_Handler(void)
{
// this function will be called when a timer 1 interrupt occurs
tmsClock++;
}
The handler simply increments a 16-bit counter, every 0.00655 seconds, which rolls over every 429.49 seconds. Then, I wrote these functions to fetch the 32bit snapshot of the timer:unsigned int GetTick(void) //Gets 16-bit timer value
{
unsigned char Temp_Buf; // 8-bit temporary buffer
unsigned int Timer_Snapshot; // 16-bit variable

Temp_Buf = TMR1L; // TMR1L must be read before TMR1H
Timer_Snapshot = TMR1H;
Timer_Snapshot <<= 8; // move TMR1H data to the upper half of the variable
Timer_Snapshot += Temp_Buf; // we now have all sixteen bits

return Timer_Snapshot;
}

unsigned long GetTime(void) //Gets 32-bit timer value
{
unsigned long ThisTick;
ThisTick=tmsClock;
ThisTick <<= 16; //Mutliply by 65536
ThisTick += GetTick(); //Add timer snapshot
return ThisTick;
}

Now GetTime() works as intended, except every second or two I get a strange (really large) value returned. Any ideas?

BTW: I discovered this error around 3:00am on ship day, which was wreaking havoc on our autonomuous code. Without a controller to test on, I haven't been able to trace the problem.

[Astronouth7303]

Trying to set up a 32-bit 10Mhz timer...

I initialized Timer1 like this:
...
The handler simply increments a 16-bit counter, every 0.00655 seconds, which rolls over every 429.49 seconds. Then, I wrote these functions to fetch the 32bit snapshot of the timer:
...
Now GetTime() works as intended, except every second or two I get a strange (really large) value returned. Any ideas?

BTW: I discovered this error around 3:00am on ship day, which was wreaking havoc on our autonomuous code. Without a controller to test on, I haven't been able to trace the problem.

YOU SHIPPED YOUR CONTROLLER?!?!? You still have your EDU, right?

In GetTick(), why not just set Timer_Snapshot to tmsClock? Doesn't the interupt go off every tick? or just on overflow?

[Random Dude]

Now GetTime() works as intended, except every second or two I get a strange (really large) value returned. Any ideas?



Define really large. As do you think the error is in the high 16 bit or the low 16?

[roknjohn]

Define really large. As do you think the error is in the high 16 bit or the low 16?
Well, that's a good question. It appeared to be in the high 16 bits of the GetTime() result. My trace output code looked like this:
printf("clock=%6d\n",tmsClock);
printf("timer=%lx\n",(unsigned long) GetTime());

The tmsClock value always looked okay. The GetTime() would accend as expected but I would get some "noise" in the high 16 bits.

Since my terminal program converted the hexstring to decimal, I wasn't able to issolate it to ONLY the high 16.

[Astronouth7303]

Printf expects signed ints. Use the other guy's lib. (See Getting Long Data)

[Mark McLeod]

printf("timer=%lx\n",(unsigned long) GetTime());

I agree with Jamie, this printf will return bogus results. It only processes 16 bits and treats them as a signed int.

[edit]My error. I forgot about the %lx format being available in printf. Our original issue with printing longs was with interpreting signed longs easily. Thanks for the correction Random.

[Random Dude]

I agree with Jamie, this printf will return bogus results. It only processes 16 bits and treats them as a signed int.


No, the %lx directive supports longs.




Though, as to the orignial question, I think it may be a critical section problem, where the interrupt code is running during a critical part of the main code. Specifically:

ThisTick=tmsClock;

That line actually compiles to about 10 lines of assembly. If the interrupt occurs during that section, really odd things can happen. You may need to disable interrupts right before that, and reenable them right after it.

[edit] Further thought on this (and clarification as to the actual problem) makes me realize that this wouldn't occur quite that often.[/edit

[roknjohn]

Here is the ouput using the EDU controller: (I only output a line every 5th program loop) I marked lines that contain errors with asteriks.

IFI User Processor Initialized ...
GetTime() = edb4f tmsClock = 15
GetTime() = 1bd3cc tmsClock = 28
GetTime() = 28cc4b tmsClock = 41
GetTime() = 35c4c1 tmsClock = 54
GetTime() = 42bd32 tmsClock = 67
GetTime() = 4fb5b7 tmsClock = 79
GetTime() = 5cae32 tmsClock = 92
GetTime() = 69a6a8 tmsClock = 105
GetTime() = 769f21 tmsClock = 118
GetTime() = 83979a tmsClock = 131
GetTime() = 909018 tmsClock = 144
GetTime() = 9d8894 tmsClock = 157
GetTime() = aa8109 tmsClock = 170
GetTime() = b77980 tmsClock = 183
GetTime() = c47201 tmsClock = 196
GetTime() = d16a78 tmsClock = 209
GetTime() = de62f5 tmsClock = 222
GetTime() = eb5b76 tmsClock = 235
GetTime() = f853f0 tmsClock = 248
GetTime() = 1054c66 tmsClock = 261
GetTime() = 11244e1 tmsClock = 274
GetTime() = 11f3d62 tmsClock = 287
GetTime() = 12c35db tmsClock = 300
GetTime() = 1392e5a tmsClock = 313
GetTime() = 14626d7 tmsClock = 326
GetTime() = 1531f4e tmsClock = 339
GetTime() = 16017d1 tmsClock = 352
GetTime() = 16d104a tmsClock = 365
GetTime() = 17a8cf tmsClock = 378 *****
GetTime() = 187181 tmsClock = 391 *****
GetTime() = 193f9bd tmsClock = 404
GetTime() = 1a0f239 tmsClock = 417
GetTime() = 1adeab2 tmsClock = 430
GetTime() = 1bae32f tmsClock = 443
GetTime() = 1c7dba8 tmsClock = 456
GetTime() = 1d4d425 tmsClock = 469
GetTime() = 1e1cca0 tmsClock = 482
GetTime() = 1eec51b tmsClock = 495
GetTime() = 1fbbd96 tmsClock = 508
GetTime() = 208b611 tmsClock = 521
GetTime() = 215ae8c tmsClock = 533
GetTime() = 222a707 tmsClock = 546
GetTime() = 22f9f83 tmsClock = 559
GetTime() = 23c97f9 tmsClock = 572
GetTime() = 249907c tmsClock = 585
GetTime() = 25688fd tmsClock = 598
GetTime() = 2638172 tmsClock = 611
GetTime() = 27079ee tmsClock = 624
GetTime() = 27d7263 tmsClock = 637
GetTime() = 28a6ae6 tmsClock = 650
GetTime() = 2976363 tmsClock = 663
GetTime() = 2a45bdc tmsClock = 676
GetTime() = 2b1545e tmsClock = 689
GetTime() = 2be4cd5 tmsClock = 702
GetTime() = 2cb4554 tmsClock = 715
GetTime() = 2d83dcb tmsClock = 728
GetTime() = 2e5364a tmsClock = 741
GetTime() = 2f22ec5 tmsClock = 754
GetTime() = 2ff2740 tmsClock = 767
GetTime() = 30c1fb2 tmsClock = 780
GetTime() = 319182a tmsClock = 793
GetTime() = 32610b1 tmsClock = 806
GetTime() = 33392a tmsClock = 819 *****
GetTime() = 3401e4 tmsClock = 832 *****
GetTime() = 34cfa20 tmsClock = 845
GetTime() = 359f29d tmsClock = 858
GetTime() = 366eb16 tmsClock = 871
GetTime() = 373e393 tmsClock = 884
GetTime() = 380dc08 tmsClock = 897
GetTime() = 38dd489 tmsClock = 910
GetTime() = 39acd02 tmsClock = 923
GetTime() = 3a7c57f tmsClock = 936
GetTime() = 3b4bdf9 tmsClock = 949
GetTime() = 3c1b66b tmsClock = 962
GetTime() = 3ceaeea tmsClock = 974
GetTime() = 3dba761 tmsClock = 987
GetTime() = 3e89fe0 tmsClock = 1000
GetTime() = 3f59861 tmsClock = 1013
GetTime() = 40290d6 tmsClock = 1026
GetTime() = 40f8957 tmsClock = 1039
GetTime() = 41c81cb tmsClock = 1052
GetTime() = 4297a4d tmsClock = 1065
GetTime() = 43672c2 tmsClock = 1078
GetTime() = 4436b43 tmsClock = 1091
GetTime() = 45063b7 tmsClock = 1104
GetTime() = 45d5c3d tmsClock = 1117
GetTime() = 46a54b8 tmsClock = 1130
GetTime() = 4774d2f tmsClock = 1143
GetTime() = 48445a4 tmsClock = 1156
GetTime() = 4913e25 tmsClock = 1169
GetTime() = 49e36a4 tmsClock = 1182
GetTime() = 4ab2f1f tmsClock = 1195
GetTime() = 4b82795 tmsClock = 1208
GetTime() = 4c5200e tmsClock = 1221
GetTime() = 4d21889 tmsClock = 1234
GetTime() = 4df110c tmsClock = 1247
GetTime() = 4ec98c tmsClock = 1260 *****
GetTime() = 4f9245 tmsClock = 1273 *****
GetTime() = 505fa7c tmsClock = 1286
GetTime() = 512f2f7 tmsClock = 1299


It looks like the last hex digit is being dropped every so often.

[Random Dude]

Here is the ouput using the EDU controller: (I only output a line every 5th program loop) I marked lines that contain errors with asteriks.

GetTime() = 16017d1 tmsClock = 352
GetTime() = 16d104a tmsClock = 365
GetTime() = 17a8cf tmsClock = 378 *****
GetTime() = 187181 tmsClock = 391 *****



It looks like the last hex digit is being dropped every so often.

Actually it's not the last one... the output you should be getting is

GetTime() = 016017d1 tmsClock = 352
GetTime() = 016d104a tmsClock = 365
GetTime() = 017a08cf tmsClock = 378 *****
GetTime() = 01870181 tmsClock = 391 *****


Notice the extra 0's. The problem is the printf function doesn't zero pad the output like it should. That is 'ok' for the ints, but for the longs it causes problems (In the printf lib, the printi function actually gets called twice for longs. once for each word.)

[roknjohn]

You are right. Thanks for pointing that out.

It appears the timer is actually working correctly. Well, that's one less thing to worry about. Now, back to other things.