problems combining millis() and GPS timekeeping

I am working on a data logger that uses a GPS to record precise times of data (using pulse-per-second output). However, because it needs to log 40 samples per second, I use "delay" and "millis" to determine when to log each sample.

The problem is that the two timing methods here disagree. When I look at the output, millis thinks that 900 to 925 milliseconds have passed between pulses, when in reality it's exactly 1000 (GPS timing is reliable).

The GPS pulses trigger an interrupt that increments a variable. I've heard that millis and delay don't work inside interrupts, but it's hard for me to imagine that something as small as incrementing a variable could cause timing errors of 75-100 ms outside the interrupt.

Anyone have any idea how to resolve this?

Many thanks,
-Jake

ajakef:
I am working on a data logger that uses a GPS to record precise times of data (using pulse-per-second output). However, because it needs to log 40 samples per second, I use "delay" and "millis" to determine when to log each sample.

The problem is that the two timing methods here disagree. When I look at the output, millis thinks that 900 to 925 milliseconds have passed between pulses, when in reality it's exactly 1000 (GPS timing is reliable).

The GPS pulses trigger an interrupt that increments a variable. I've heard that millis and delay don't work inside interrupts, but it's hard for me to imagine that something as small as incrementing a variable could cause timing errors of 75-100 ms outside the interrupt.

Anyone have any idea how to resolve this?

Many thanks,
-Jake

Are you saying that you are using millis or delay within an ISR? If so, how much time is being spent in the ISR?

Which microcontroller are you using? Even with a ceramic resonator, the system clock (and hence millis and delay) ought to be within 1%, unless a LOT of time is being spent with interrupts inhibited, which can cause issues.

Delay will not work in an ISR as it depends on interrupts to increment its value and normally interrupts are inhibited in an ISR, so when the GPS interrupt fires, do whatever is necessary and get out in a hurry (of course this is good general practice for any ISR). millis will "work" within an ISR in that it will return a value, but it will not increment due to the inhibited interrupt already mentioned.

The ISR is a one-liner that only increments a variable (which should take basically no time at all), and it is only triggered once per second. The delay and millis calls are all outside it. It seems like such a small thing; I can't understand why it would cause a problem.

Every 0.025 seconds, the program reads three analog pins and writes those values (along with their millis times and the millis time of the last GPS pulse) to an SD card buffer. The buffer is flushed to the card every second. I don't know if analog reading or SD card writing could cause problems like this.

Well that certainly is the minimal ISR. Not sure about SD causing problems, maybe someone else can comment or I might have a look through the code. A bit of a long shot, but could the system clock be off by that much? Do you have a way of checking? If nothing else, take out the sensor reads and the SD write, and then see how long millis() thinks it is between GPS pulses.

I've also been playing with a GPS recently. Try this sketch, hook the 1 PPS signal to the INT0 pin.

#include <Streaming.h>    //http://arduiniana.org/libraries/streaming/

#define LED LED_BUILTIN

volatile boolean intFlag;
boolean ledState;

void setup(void)
{
    Serial.begin(115200);
    pinMode(LED, OUTPUT);

    EICRA = _BV(ISC01);          //external interrupt on falling edge
    EIFR = _BV(INTF0);           //clear the interrupt flag
    EIMSK = _BV(INT0);           //enable external interrupt
}

void loop(void)
{
    if (intFlag) {
        intFlag = false;
        digitalWrite(LED, ledState = !ledState);
        Serial << millis() << endl;
    }
}

ISR(INT0_vect)
{
    intFlag = true;
}

The µC clock in this case is crystal-controlled, so maybe a bit better than a resonator, but I get output like this:

287
1287
2287
3287
4287
5286
6287
7286
8287
9286
10287
11286
12286
13286
14286
15286
16286
17286
18286
19286
20286

I tried that code and got the same output as you. I'm not familiar with how you use the interrupt here though--I used attachInterrupt in mine. I'll try looking up the way you did it and see if it works in my code.

Thanks for your help!

ajakef:
I tried that code and got the same output as you. I'm not familiar with how you use the interrupt here though--I used attachInterrupt in mine. I'll try looking up the way you did it and see if it works in my code.

I just set the registers up directly rather than using the Arduino functions. See the datasheet for details.

This code should be equivalent:

#include <Streaming.h>    //http://arduiniana.org/libraries/streaming/

#define LED LED_BUILTIN

volatile boolean intFlag;
boolean ledState;

void setup(void)
{
    Serial.begin(115200);
    pinMode(LED, OUTPUT);
    attachInterrupt(0, flagInt0, FALLING);
}

void loop(void)
{
    if (intFlag) {
        intFlag = false;
        digitalWrite(LED, ledState = !ledState);
        Serial << millis() << endl;
    }
}

void flagInt0(void)
{
    intFlag = true;
}

Ok, I tried changing the way I did the interrupt. Didn't help. So, I started cutting things out of the code to see what made a difference. The part that proved critical was setting up a serial connection (using SoftwareSerial) to the GPS and querying the date and time. I only asked it for a single time at the very beginning of the code (in setup) because it's a cumbersome process, but even doing it once will affect millis readings in the rest of the program. I guess it must set up a bunch of interrupts for monitoring the GPS that take more time.

Interestingly, I can set up the connection (softwareSerial.begin(4800) ) and not use it afterward and it won't mess up the millis readings, but as soon as I use it once (like by softwareSerial.print() ) it starts causing problems.

Do you know if it's possible to close a serial connection to make this stop? Maybe by setting the pins to a different mode or something?

Post your code so we can have a look.

Here's the interesting part. query() is called once by setup() and requests time/location info from the GPS using readline(). That's the only time it's used. The rest of the code is given below.

void query(){
  gpsSerial.begin(4800); // 4800 baud rate
		// send instructions to GPS about data needed
  gpsSerial.print(SERIAL_SET);  delay(250);
  gpsSerial.print(DDM_OFF);  delay(250);
  gpsSerial.print(GGA_ON);  delay(250);
  gpsSerial.print(GLL_OFF);  delay(250);
  gpsSerial.print(GSA_OFF);  delay(250);
  gpsSerial.print(GSV_OFF);  delay(250);
  gpsSerial.print(RMC_OFF);  delay(250);
  gpsSerial.print(VTG_OFF);  delay(250);
  gpsSerial.print(WAAS_OFF);  delay(250);

  int done = 0;
  while(!done){
    readline(); // this reads serial input and updates the buffer
    if(strncmp(buffer, "$GPGGA",6) == 0){
      Serial.print(millis()); Serial.print(","); Serial.println(buffer);
      outfile.print(millis()); outfile.print(","); outfile.println(buffer);
      done = 1;
    }
  }
}

/////////////////////////////////////////////////////////////////////
void readline() { // this reads serial input and updates the buffer
  char c;
  uint8_t bufferidx = 0;
  digitalWrite(red, HIGH);
  int n = 0;
  while (1) {
    n++; if(n > 10000){break;}
    if(gpsSerial.available()){
      c = gpsSerial.read();
      if (c == -1){
        continue;
      }
      if (c == '\n'){
        continue;
      }
      if ((bufferidx == 90-1) || (c == '\r')) { // buffer size 90
        buffer[bufferidx] = 0;
        return;
      }
      buffer[bufferidx++]= c;
    }
    else{
    }
  }
  digitalWrite(red, LOW);
  digitalWrite(green, HIGH);
} // end of readline

Full code:

// user settings

#define SAMPLE_INT 25   // number of ms between samples
#define FLUSH_INT 1000  // number of ms between writing buffer to SD
#define USE_SERIAL 1 // if 1, print info to serial connection at 115200
#define AREF 3.3 // 
////////////////////////////////////////////////////////////////////////
////////////////////////////////////////////////////////////////////////

#include <SD.h>
#include <GPSconfig.h>
#include <SoftwareSerial.h>

// digital pins for LEDs
#define red 6
#define green 5

// measurement pins
#define CHAN1_PIN 0 
#define CHAN2_PIN 1 
#define CHAN3_PIN 2
#define CHAN1_GND 3 // these are for the pins fixed at 0 volts 
#define CHAN2_GND 4
#define CHAN3_GND 5

#define POWERPIN 7 // for GPS
#define CHIPSELECT 10 // required for SD card use

// Vcc measurement stuff
#define BANDGAPREF 14 // special indicator that we want to measure the bandgap
#define aref_voltage 3.3 // we tie 3.3V to ARef and measure it with a multimeter!
#define bandgap_voltage 1.1 // this is not super guaranteed but its not -too- off

// initialize global variables
uint32_t t = 0;
uint32_t lastflush = 0; 
File outfile;
SoftwareSerial gpsSerial = SoftwareSerial(3, 4);
char buffer[90];
volatile uint32_t pps = 0;
/////////////////////////////////////////////////////////////////////

void readline() { // this reads serial input and updates the buffer
  char c;
  uint8_t bufferidx = 0;
  digitalWrite(red, HIGH);
  int n = 0;
  while (1) {
    n++; if(n > 10000){break;}
    if(gpsSerial.available()){
      c = gpsSerial.read();
      if (c == -1){
        continue;
      }
      if (c == '\n'){
        continue;
      }
      if ((bufferidx == 90-1) || (c == '\r')) { // buffer size 90
        buffer[bufferidx] = 0;
        return;
      }
      buffer[bufferidx++]= c;
    }
    else{
    }
  }
  digitalWrite(red, LOW);
  digitalWrite(green, HIGH);
} // end of readline

/////////////////////////////////////////////////////////////////////
void query(){
  gpsSerial.begin(4800); // 4800 baud rate
		// send instructions to GPS about data needed
  gpsSerial.print(SERIAL_SET);  delay(250);
  gpsSerial.print(DDM_OFF);  delay(250);
  gpsSerial.print(GGA_ON);  delay(250);
  gpsSerial.print(GLL_OFF);  delay(250);
  gpsSerial.print(GSA_OFF);  delay(250);
  gpsSerial.print(GSV_OFF);  delay(250);
  gpsSerial.print(RMC_OFF);  delay(250);
  gpsSerial.print(VTG_OFF);  delay(250);
  gpsSerial.print(WAAS_OFF);  delay(250);

  int done = 0;
  while(!done){
    readline(); // this reads serial input and updates the buffer
    if(strncmp(buffer, "$GPGGA",6) == 0){
      Serial.print(millis()); Serial.print(","); Serial.println(buffer);
      outfile.print(millis()); outfile.print(","); outfile.println(buffer);
      done = 1;
    }
  }
}

/////////////////////////////////////////////////////////////////////
void error(char *str)
{
#if USE_SERIAL
  Serial.print("error: ");
  Serial.println(str);
#endif
  outfile.println(); outfile.println(str);
  outfile.flush();
  digitalWrite(red, HIGH);
  while(1);
}
void PPS(void)
{
  pps++;
}
/*
ISR(INT0_vect)
{
  pps++;
}
*/
//////////////////////////////////////////////////////////////////////
void setup(void)
{
  
  // start LEDs
  pinMode(red, OUTPUT);
  pinMode(green, OUTPUT);
  
  // start ground pins for analog channels
  analogWrite(CHAN1_GND, 0);
  analogWrite(CHAN2_GND, 0);
  analogWrite(CHAN3_GND, 0);
  
  // start serial connection, if necessary
#if USE_SERIAL
  Serial.begin(115200);
  Serial.println();
  Serial.print("SD card setup...");
#endif


  // setup card
  pinMode(CHIPSELECT, OUTPUT);
  if(!SD.begin(CHIPSELECT)){
    error("No SD card detected!");
  }

#if USE_SERIAL
  Serial.print("detected...");
#endif

  // create a new file
  char filename[] = "RECORD00.txt";
  for (uint8_t i = 0; i < 100; i++) {
    filename[6] = i/10 + '0';
    filename[7] = i%10 + '0';
    if (! SD.exists(filename)) {
      // only open a new file if it doesn't exist
      outfile = SD.open(filename, FILE_WRITE);
      break; // leave the loop!
    }
  }
  
  if(!outfile) {
    error("Failed to open file!");
  }

#if USE_SERIAL
  Serial.print("writing to file ");
//  Serial.println(filename);
#endif

  // GPS stuff:
  pinMode(3, INPUT);
  pinMode(4, OUTPUT);
  pinMode(POWERPIN, OUTPUT);
  digitalWrite(POWERPIN, LOW);

    // set a PPS interrupt (pin 2)
/*  EICRA = _BV(ISC01);          //external interrupt on falling edge
  EIFR = _BV(INTF0);           //clear the interrupt flag
  EIMSK = _BV(INT0);           //enable external interrupt
  */
  
  Serial.println("Ready!");
  delay(2000);

  query(); // request GPS time
  attachInterrupt(0, PPS, RISING);
  
  outfile.println("time(ms),chan1,chan2,chan3,vcc,ppstime");
#if USE_SERIAL
  Serial.println("time(ms),chan1,chan2,chan3,vcc,ppstime,flush");
#endif 
 
}

void loop(void)
{
  // delay for the amount of time we want between readings
  if((millis() - t) < SAMPLE_INT){ // JFA 2013/1/25 14:28--try to avoid skipped samples by only delaying if it hasn't already reached the next one
    delay((SAMPLE_INT - 1) - (millis() % SAMPLE_INT));
  }
  
  // log milliseconds since starting
  t = millis();
  outfile.print(t); outfile.print(", "); 

#if USE_SERIAL
  Serial.print(t); Serial.print(", "); 
#endif
  
  // read analog channels
  analogRead(CHAN1_PIN); delay(1); int chan1 = analogRead(CHAN1_PIN);
  analogRead(CHAN2_PIN); delay(1); int chan2 = analogRead(CHAN2_PIN);
  analogRead(CHAN3_PIN); delay(1); int chan3 = analogRead(CHAN3_PIN);
  
  // Log the estimated 'VCC' voltage by measuring the internal 1.1v ref
  analogRead(BANDGAPREF); delay(1); int refReading = analogRead(BANDGAPREF);
  float supplyvoltage = (bandgap_voltage * 1024) / refReading;
 
  // write to SD card buffer
  outfile.print(chan1); outfile.print(",");
  outfile.print(chan2); outfile.print(",");
  outfile.print(chan3); outfile.print(",");
  outfile.print(supplyvoltage); outfile.print(",");
  outfile.print(pps);
  outfile.println();
  
  // write to the serial connection
#if USE_SERIAL
  Serial.print(chan1); Serial.print(",");
  Serial.print(chan2); Serial.print(",");
  Serial.print(chan3); Serial.print(",");
  Serial.print(supplyvoltage); Serial.print(",");
  Serial.print(pps);
#endif 

 
  // check to see if it's time to flush SD buffer.  If yes, flush it.  This transfers 2048 bytes.
  if ((millis() - lastflush) < FLUSH_INT){
#if USE_SERIAL
  Serial.println(",0");
#endif 
  }
  else{
    lastflush = millis();
  
    // blink red LED to indicate flush
    digitalWrite(red, HIGH);
    outfile.flush();
    digitalWrite(red, LOW);
  #if USE_SERIAL
    Serial.println(",1");
  #endif 
  }
}

The dependency GPSconfig.h is attached.

GPSconfig.h (1.8 KB)

Just to verify, when you ran the code in Reply #4, the numbers were very close to being 1000 different from one to the next, correct?

Which version of the IDE are you using?

That's right. And when I comment out the query() call to get the GPS time/location, the millis() time difference between pulses is also close to 1000.

I'm using v 1.0 of the IDE (that's what it says in "About Arduino", anyway. And I'm using a Duemilanove board.

So would SoftwareSerial be the prime suspect here?

It looks to me like SoftwareSerial keeps interrupts inhibited while it's transmitting. Given 4800 baud and the length of the messages, I'd guess that could be 40-50ms at a time, which is a fairly long time, I'd think that might impact the millis() counter, but I'd have to experiment.

Looks like the code has options to use SoftwareSerial or hardware serial? Does it work ok with hardware serial?

The part I don't get is why millis() continues to run slow after all the SoftwareSerial calls are done.

Solved. I couldn't use a hardware serial connection (Duemilanove, so I only have one and it's for uploading programs to the board), but you got me thinking about alternatives to SoftwareSerial. And it turned out that switching to AltSoftSerial fixed it--the millis count is accurate again.

The downside of AltSoftSerial vs. SoftwareSerial is that it only gets one serial connection and it has to be on pins 8 and 9, but for my project that's fine and a small price to pay for accurate timing.

Thanks for your help! It's very much appreciated.

Hey, good deal! And thank you because I was not aware of AltSoftSerial. Was just reading about it at pjrc.com. Looks like a good one to have in the hip pocket!

The 1sec pulse from a GPS module is not exactly 1sec. It has a jitter (~few milliseconds) thus the short time precision is poor. Only when averaged over a longer time period (~hours) it follows the "GPS" precision, however. Normally, you do not want to use 1sec pulses from a GPS module for a measurement. It is used for disciplining of a quality crystal oscillator (ie 5-10MHz) instead. Google "crystal oscillator disciplining"..

pito:
The 1sec pulse from a GPS module is not exactly 1sec. It has a jitter (~few milliseconds) thus the short time precision is poor. Only when averaged over a longer time period (~hours) it follows the "GPS" precision, however. Normally, you do not want to use 1sec pulses from a GPS module for a measurement. It is used for disciplining of a quality crystal oscillator (ie 5-10MHz) instead. Google "crystal oscillator disciplining"..
GPS disciplined oscillator - Wikipedia

I wondered about short term jitter and yes I am aware of disciplined oscillators. Yet, using this technique, I have measured several µCs with crystals for their system clock, and having one of the timers set to create a 1MHz output, I can watch the readings for minutes at a time and I usually don't see more than a single digit bobble. A few milliseconds jitter would cause variations of thousands of Hertz. Perhaps this particular GPS receiver uses a disciplined oscillator for its 1 PPS output. Don't remember but I'll double check the datasheet.

Here is some typical output, I was fairly amazed. Just the first minute's worth in the quote but the attached file has ten minutes or so. I've checked this particular unit several times over as many days, and the frequency is always the same, so I'm not seeing any longer-term variation either.

GPS Frequency Counter
2: 1,000,003 Hz
4: 1,000,003 Hz
6: 1,000,004 Hz
8: 1,000,003 Hz
10: 1,000,003 Hz
12: 1,000,003 Hz
14: 1,000,004 Hz
16: 1,000,002 Hz
18: 1,000,003 Hz
20: 1,000,003 Hz
22: 1,000,003 Hz
24: 1,000,003 Hz
26: 1,000,003 Hz
28: 1,000,003 Hz
30: 1,000,003 Hz
32: 1,000,000 Hz
34: 1,000,003 Hz
36: 1,000,003 Hz
38: 1,000,003 Hz
40: 1,000,003 Hz
42: 1,000,003 Hz
44: 1,000,003 Hz
46: 1,000,003 Hz
48: 1,000,003 Hz
50: 1,000,003 Hz
52: 1,000,003 Hz
54: 1,000,003 Hz
56: 1,000,003 Hz
58: 1,000,003 Hz
60: 1,000,003 Hz

CoolTerm Capture 2013-01-30 19-13-47.txt (6.09 KB)

Which GPS are you using to get 40 samples per second ?

michinyon:
Which GPS are you using to get 40 samples per second ?

I read that he was logging data 40/sec, not that the GPS was providing updates at that rate.