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]

Originally Posted by roknjohn

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]

Originally Posted by roknjohn

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]

Originally Posted by roknjohn

 
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]

Originally Posted by Mark McLeod

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]

Originally Posted by 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.

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.