Is it possible to find the time taken by millis?
If you want to know exactly how long something will take, there is only one solution: Look at the disassembly!
Starting with the minimal code:
void setup(){};
volatile uint16_t x;
void loop()
{
x = millis();
}
This code compiled and then fed into avr-objdump -S produces a documented disassembly. Here are the interesting excerpts:
void loop() produces:
000000a8 <loop>:
a8: 0e 94 a7 00 call 0x14e ; 0x14e <millis>
ac: 60 93 00 01 sts 0x0100, r22
b0: 70 93 01 01 sts 0x0101, r23
b4: 80 93 02 01 sts 0x0102, r24
b8: 90 93 03 01 sts 0x0103, r25
bc: 08 95 ret
Which is a function call (call), four copies (which copy each of the bytes in the uint32_t return value of millis() (note that the arduino docs call this a long, but they are incorrect to not be explicitly specifying the variable sizes)), and finally the function return.
call requires 4 clock cycles, and each sts requires 2 clock cycles, so we have a minimum of 12 clock cycles just for function call overhead.
Now, lets look at the disassembly of the <millis> function, which is located at 0x14e:
unsigned long millis()
{
unsigned long m;
uint8_t oldSREG = SREG;
14e: 8f b7 in r24, 0x3f ; 63
// disable interrupts while we read timer0_millis or we might get an
// inconsistent value (e.g. in the middle of a write to timer0_millis)
cli();
150: f8 94 cli
m = timer0_millis;
152: 20 91 08 01 lds r18, 0x0108
156: 30 91 09 01 lds r19, 0x0109
15a: 40 91 0a 01 lds r20, 0x010A
15e: 50 91 0b 01 lds r21, 0x010B
SREG = oldSREG;
162: 8f bf out 0x3f, r24 ; 63
return m;
}
164: b9 01 movw r22, r18
166: ca 01 movw r24, r20
168: 08 95 ret
As you can see, the millis() function is fairly simple:
insaves the interrupt register settings (1 cycle)cliturns off the interrupts (1 cycle)ldscopy one of the 4 bytes of the current value of the milli counter into a temporary register (2 clock cycles)ldsByte 2 (2 clock cycles)ldsByte 3 (2 clock cycles)ldsByte 4 (2 clock cycles)outrestore interrupt settings (1 clock cycle)movwshuffle registers around (1 clock cycle)movwand again (1 clock cycle)retreturn from subroutine (4 cycles)
So, if we add them all up, we have a total of 17 clock cycles in the millis() function itself, plus a call overhead of 12, for a total of 29 clock cycles.
Assuming a 16 Mhz clock rate (most arduinos), each clock cycle is 1 / 16e6 seconds, or 0.0000000625 seconds, which is 62.5 nanoseconds. 62.5 ns * 29 = 1.812 microseconds.
Therefore, the total execution time for a single millis() call on most Arduinos will be 1.812 microseconds.
AVR Assembly reference
As a side-note, there is space for optimization here! If you update the unsigned long millis(){} function definition to be inline unsigned long millis(){}, you would remove the call overhead (at the cost of slightly larger code size). Furthermore, it looks like the compiler is doing two unnecessary moves (the two movw calls, but I haven't looked at it that closely).
Really, considering the function call overhead is 5 instructions, and the actual contents of the millis() function is only 6 instructions, I think the millis() function should really be inline by default, but the Arduino codebase is rather poorly optimized.
Here is the full disassemby for anyone interested:
sketch_feb13a.cpp.elf: file format elf32-avr
Disassembly of section .text:
00000000 <__vectors>:
SREG = oldSREG;
return m;
}
unsigned long micros() {
0: 0c 94 34 00 jmp 0x68 ; 0x68 <__ctors_end>
4: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
8: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
c: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
10: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
14: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
18: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
1c: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
20: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
24: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
28: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
2c: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
30: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
34: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
38: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
3c: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
40: 0c 94 5f 00 jmp 0xbe ; 0xbe <__vector_16>
44: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
48: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
4c: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
50: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
54: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
58: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
5c: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
60: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
64: 0c 94 51 00 jmp 0xa2 ; 0xa2 <__bad_interrupt>
00000068 <__ctors_end>:
68: 11 24 eor r1, r1
6a: 1f be out 0x3f, r1 ; 63
6c: cf ef ldi r28, 0xFF ; 255
6e: d8 e0 ldi r29, 0x08 ; 8
70: de bf out 0x3e, r29 ; 62
72: cd bf out 0x3d, r28 ; 61
00000074 <__do_copy_data>:
74: 11 e0 ldi r17, 0x01 ; 1
76: a0 e0 ldi r26, 0x00 ; 0
78: b1 e0 ldi r27, 0x01 ; 1
7a: e2 e0 ldi r30, 0x02 ; 2
7c: f2 e0 ldi r31, 0x02 ; 2
7e: 02 c0 rjmp .+4 ; 0x84 <.do_copy_data_start>
00000080 <.do_copy_data_loop>:
80: 05 90 lpm r0, Z+
82: 0d 92 st X+, r0
00000084 <.do_copy_data_start>:
84: a0 30 cpi r26, 0x00 ; 0
86: b1 07 cpc r27, r17
88: d9 f7 brne .-10 ; 0x80 <.do_copy_data_loop>
0000008a <__do_clear_bss>:
8a: 11 e0 ldi r17, 0x01 ; 1
8c: a0 e0 ldi r26, 0x00 ; 0
8e: b1 e0 ldi r27, 0x01 ; 1
90: 01 c0 rjmp .+2 ; 0x94 <.do_clear_bss_start>
00000092 <.do_clear_bss_loop>:
92: 1d 92 st X+, r1
00000094 <.do_clear_bss_start>:
94: ad 30 cpi r26, 0x0D ; 13
96: b1 07 cpc r27, r17
98: e1 f7 brne .-8 ; 0x92 <.do_clear_bss_loop>
9a: 0e 94 f0 00 call 0x1e0 ; 0x1e0 <main>
9e: 0c 94 ff 00 jmp 0x1fe ; 0x1fe <_exit>
000000a2 <__bad_interrupt>:
a2: 0c 94 00 00 jmp 0 ; 0x0 <__vectors>
000000a6 <setup>:
a6: 08 95 ret
000000a8 <loop>:
a8: 0e 94 a7 00 call 0x14e ; 0x14e <millis>
ac: 60 93 00 01 sts 0x0100, r22
b0: 70 93 01 01 sts 0x0101, r23
b4: 80 93 02 01 sts 0x0102, r24
b8: 90 93 03 01 sts 0x0103, r25
bc: 08 95 ret
000000be <__vector_16>:
#if defined(__AVR_ATtiny24__) || defined(__AVR_ATtiny44__) || defined(__AVR_ATtiny84__)
ISR(TIM0_OVF_vect)
#else
ISR(TIMER0_OVF_vect)
#endif
{
be: 1f 92 push r1
c0: 0f 92 push r0
c2: 0f b6 in r0, 0x3f ; 63
c4: 0f 92 push r0
c6: 11 24 eor r1, r1
c8: 2f 93 push r18
ca: 3f 93 push r19
cc: 8f 93 push r24
ce: 9f 93 push r25
d0: af 93 push r26
d2: bf 93 push r27
// copy these to local variables so they can be stored in registers
// (volatile variables must be read from memory on every access)
unsigned long m = timer0_millis;
d4: 80 91 08 01 lds r24, 0x0108
d8: 90 91 09 01 lds r25, 0x0109
dc: a0 91 0a 01 lds r26, 0x010A
e0: b0 91 0b 01 lds r27, 0x010B
unsigned char f = timer0_fract;
e4: 30 91 0c 01 lds r19, 0x010C
m += MILLIS_INC;
e8: 01 96 adiw r24, 0x01 ; 1
ea: a1 1d adc r26, r1
ec: b1 1d adc r27, r1
f += FRACT_INC;
ee: 23 2f mov r18, r19
f0: 2d 5f subi r18, 0xFD ; 253
if (f >= FRACT_MAX) {
f2: 2d 37 cpi r18, 0x7D ; 125
f4: 20 f0 brcs .+8 ; 0xfe <__vector_16+0x40>
f -= FRACT_MAX;
f6: 2d 57 subi r18, 0x7D ; 125
m += 1;
f8: 01 96 adiw r24, 0x01 ; 1
fa: a1 1d adc r26, r1
fc: b1 1d adc r27, r1
}
timer0_fract = f;
fe: 20 93 0c 01 sts 0x010C, r18
timer0_millis = m;
102: 80 93 08 01 sts 0x0108, r24
106: 90 93 09 01 sts 0x0109, r25
10a: a0 93 0a 01 sts 0x010A, r26
10e: b0 93 0b 01 sts 0x010B, r27
timer0_overflow_count++;
112: 80 91 04 01 lds r24, 0x0104
116: 90 91 05 01 lds r25, 0x0105
11a: a0 91 06 01 lds r26, 0x0106
11e: b0 91 07 01 lds r27, 0x0107
122: 01 96 adiw r24, 0x01 ; 1
124: a1 1d adc r26, r1
126: b1 1d adc r27, r1
128: 80 93 04 01 sts 0x0104, r24
12c: 90 93 05 01 sts 0x0105, r25
130: a0 93 06 01 sts 0x0106, r26
134: b0 93 07 01 sts 0x0107, r27
}
138: bf 91 pop r27
13a: af 91 pop r26
13c: 9f 91 pop r25
13e: 8f 91 pop r24
140: 3f 91 pop r19
142: 2f 91 pop r18
144: 0f 90 pop r0
146: 0f be out 0x3f, r0 ; 63
148: 0f 90 pop r0
14a: 1f 90 pop r1
14c: 18 95 reti
0000014e <millis>:
unsigned long millis()
{
unsigned long m;
uint8_t oldSREG = SREG;
14e: 8f b7 in r24, 0x3f ; 63
// disable interrupts while we read timer0_millis or we might get an
// inconsistent value (e.g. in the middle of a write to timer0_millis)
cli();
150: f8 94 cli
m = timer0_millis;
152: 20 91 08 01 lds r18, 0x0108
156: 30 91 09 01 lds r19, 0x0109
15a: 40 91 0a 01 lds r20, 0x010A
15e: 50 91 0b 01 lds r21, 0x010B
SREG = oldSREG;
162: 8f bf out 0x3f, r24 ; 63
return m;
}
164: b9 01 movw r22, r18
166: ca 01 movw r24, r20
168: 08 95 ret
0000016a <init>:
void init()
{
// this needs to be called before setup() or some functions won't
// work there
sei();
16a: 78 94 sei
// on the ATmega168, timer 0 is also used for fast hardware pwm
// (using phase-correct PWM would mean that timer 0 overflowed half as often
// resulting in different millis() behavior on the ATmega8 and ATmega168)
#if defined(TCCR0A) && defined(WGM01)
sbi(TCCR0A, WGM01);
16c: 84 b5 in r24, 0x24 ; 36
16e: 82 60 ori r24, 0x02 ; 2
170: 84 bd out 0x24, r24 ; 36
sbi(TCCR0A, WGM00);
172: 84 b5 in r24, 0x24 ; 36
174: 81 60 ori r24, 0x01 ; 1
176: 84 bd out 0x24, r24 ; 36
// this combination is for the standard atmega8
sbi(TCCR0, CS01);
sbi(TCCR0, CS00);
#elif defined(TCCR0B) && defined(CS01) && defined(CS00)
// this combination is for the standard 168/328/1280/2560
sbi(TCCR0B, CS01);
178: 85 b5 in r24, 0x25 ; 37
17a: 82 60 ori r24, 0x02 ; 2
17c: 85 bd out 0x25, r24 ; 37
sbi(TCCR0B, CS00);
17e: 85 b5 in r24, 0x25 ; 37
180: 81 60 ori r24, 0x01 ; 1
182: 85 bd out 0x25, r24 ; 37
// enable timer 0 overflow interrupt
#if defined(TIMSK) && defined(TOIE0)
sbi(TIMSK, TOIE0);
#elif defined(TIMSK0) && defined(TOIE0)
sbi(TIMSK0, TOIE0);
184: ee e6 ldi r30, 0x6E ; 110
186: f0 e0 ldi r31, 0x00 ; 0
188: 80 81 ld r24, Z
18a: 81 60 ori r24, 0x01 ; 1
18c: 80 83 st Z, r24
// this is better for motors as it ensures an even waveform
// note, however, that fast pwm mode can achieve a frequency of up
// 8 MHz (with a 16 MHz clock) at 50% duty cycle
#if defined(TCCR1B) && defined(CS11) && defined(CS10)
TCCR1B = 0;
18e: e1 e8 ldi r30, 0x81 ; 129
190: f0 e0 ldi r31, 0x00 ; 0
192: 10 82 st Z, r1
// set timer 1 prescale factor to 64
sbi(TCCR1B, CS11);
194: 80 81 ld r24, Z
196: 82 60 ori r24, 0x02 ; 2
198: 80 83 st Z, r24
#if F_CPU >= 8000000L
sbi(TCCR1B, CS10);
19a: 80 81 ld r24, Z
19c: 81 60 ori r24, 0x01 ; 1
19e: 80 83 st Z, r24
sbi(TCCR1, CS10);
#endif
#endif
// put timer 1 in 8-bit phase correct pwm mode
#if defined(TCCR1A) && defined(WGM10)
sbi(TCCR1A, WGM10);
1a0: e0 e8 ldi r30, 0x80 ; 128
1a2: f0 e0 ldi r31, 0x00 ; 0
1a4: 80 81 ld r24, Z
1a6: 81 60 ori r24, 0x01 ; 1
1a8: 80 83 st Z, r24
// set timer 2 prescale factor to 64
#if defined(TCCR2) && defined(CS22)
sbi(TCCR2, CS22);
#elif defined(TCCR2B) && defined(CS22)
sbi(TCCR2B, CS22);
1aa: e1 eb ldi r30, 0xB1 ; 177
1ac: f0 e0 ldi r31, 0x00 ; 0
1ae: 80 81 ld r24, Z
1b0: 84 60 ori r24, 0x04 ; 4
1b2: 80 83 st Z, r24
// configure timer 2 for phase correct pwm (8-bit)
#if defined(TCCR2) && defined(WGM20)
sbi(TCCR2, WGM20);
#elif defined(TCCR2A) && defined(WGM20)
sbi(TCCR2A, WGM20);
1b4: e0 eb ldi r30, 0xB0 ; 176
1b6: f0 e0 ldi r31, 0x00 ; 0
1b8: 80 81 ld r24, Z
1ba: 81 60 ori r24, 0x01 ; 1
1bc: 80 83 st Z, r24
#if defined(ADCSRA)
// set a2d prescale factor to 128
// 16 MHz / 128 = 125 KHz, inside the desired 50-200 KHz range.
// XXX: this will not work properly for other clock speeds, and
// this code should use F_CPU to determine the prescale factor.
sbi(ADCSRA, ADPS2);
1be: ea e7 ldi r30, 0x7A ; 122
1c0: f0 e0 ldi r31, 0x00 ; 0
1c2: 80 81 ld r24, Z
1c4: 84 60 ori r24, 0x04 ; 4
1c6: 80 83 st Z, r24
sbi(ADCSRA, ADPS1);
1c8: 80 81 ld r24, Z
1ca: 82 60 ori r24, 0x02 ; 2
1cc: 80 83 st Z, r24
sbi(ADCSRA, ADPS0);
1ce: 80 81 ld r24, Z
1d0: 81 60 ori r24, 0x01 ; 1
1d2: 80 83 st Z, r24
// enable a2d conversions
sbi(ADCSRA, ADEN);
1d4: 80 81 ld r24, Z
1d6: 80 68 ori r24, 0x80 ; 128
1d8: 80 83 st Z, r24
// here so they can be used as normal digital i/o; they will be
// reconnected in Serial.begin()
#if defined(UCSRB)
UCSRB = 0;
#elif defined(UCSR0B)
UCSR0B = 0;
1da: 10 92 c1 00 sts 0x00C1, r1
#endif
}
1de: 08 95 ret
000001e0 <main>:
#include <Arduino.h>
int main(void)
1e0: cf 93 push r28
1e2: df 93 push r29
{
init();
1e4: 0e 94 b5 00 call 0x16a ; 0x16a <init>
#if defined(USBCON)
USBDevice.attach();
#endif
setup();
1e8: 0e 94 53 00 call 0xa6 ; 0xa6 <setup>
for (;;) {
loop();
if (serialEventRun) serialEventRun();
1ec: c0 e0 ldi r28, 0x00 ; 0
1ee: d0 e0 ldi r29, 0x00 ; 0
#endif
setup();
for (;;) {
loop();
1f0: 0e 94 54 00 call 0xa8 ; 0xa8 <loop>
if (serialEventRun) serialEventRun();
1f4: 20 97 sbiw r28, 0x00 ; 0
1f6: e1 f3 breq .-8 ; 0x1f0 <main+0x10>
1f8: 0e 94 00 00 call 0 ; 0x0 <__vectors>
1fc: f9 cf rjmp .-14 ; 0x1f0 <main+0x10>
000001fe <_exit>:
1fe: f8 94 cli
00000200 <__stop_program>:
200: ff cf rjmp .-2 ; 0x200 <__stop_program>
Write a sketch that millis 1000 times, not by making a loop, but by copy and paste. Measure that and compare it to the actual expected time. Mind you that that the results may vary with different versions of the IDE (and its compiler in particular).
Another option is to toggle an IO pin before and after the millis call, then measure the time for a very small value and a somewhat larger value. Compare the measured timings and calculate the overhead.
The most accurate way is to take a look at the disassembly listing, the generated code. But that is not for the faint of heart. You'll have to carefully study the datasheet how long each instruction cycle takes.
I second calling millis repeatedly and then comparing actual vs. expected.
There will be some minimal overhead, but it will diminish in significance the more times you call millis().
If you look at
C:\Program Files (x86)\Arduino\Arduino ERW 1.0.5\hardware\arduino\cores\arduino\wiring.c
You can see that millis() is very tiny at only 4 instructions (cli is simply # define cli() \__asm__ \__volatile__ ("cli" ::)) and a return.
I'd call it about 10 million times using a FOR loop which has a volatile as the conditional. The volatile keyword will prevent the compiler from attempting any optimization on the loop itself.
I don't guarantee the following to be syntactically perfect..
int temp1,temp2;
temp1=millis();
for (volatile unsigned int j=0;j<1000000;++j){
temp2=millis();}
Serial.print("Execution time = ");
Serial.print((temp2-temp1,DEC);
Serial.print("ms");
my guess is that takes ~900ms or about 56us per call to millis. ( I don't have an aruduino handy ATM.