Hi,
This is based on a program that I wrote in 2012 which became somewhat "lost" in a thread with a rather unmemorable title (at least for me). I've used the program many times over the years, so have now "tidied it up" and added a few more features. However, I won't repeat much of the detail from the original thread, but just point to post #12 of this thread. The program can estimate the execution time of almost any single instruction, simple algorithm, or through to quite large subroutines, etc. on any M2 PICaxe, by comparing the internal "Timer 1" values, immediately before and after execution of the instruction(s) under test. Thus, no external hardware is required, except for a powered M2 PICaxe connected to the Program Editor / Terminal Emulator.
But first a disclaimer: It's been discussed numerous times that PICaxe program instructions do not have an absolute execution time, because the interpreter "tokens" do not (necessarily) fit neatly within the program memory byte boundaries. This means that the slightest change to the program structure can alter the execution time of the component instructions. These variations occur at the Program Editing stage so the program itself cannot "investigate" the variations which might occur, and ultimately the Programmer/User must identify any inconsistencies. However, the same program, if run multiple times, appears to give exactly the same results, which suggests that the internal System Interrupts become synchronised to the program instructions (or vice versa).
Timer 1 is primarily used by the PICaxe Operating System to time the Servo pulses, so the program may disturb the operation of these (because it increases the timing period to 65 ms). The new program also pauses the Timer between reading its Low and High bytes, which seems to have eliminated some of the occasional inconsistencies with the original program. Normally, Timer 1 appears to "always" count through 20,000 cycles, but its period is 20 ms with a SETFREQ of only m4 or m16.
The new version includes three operating modes: MODE 1 gives a similar output to the original program, indicating the number of PIC Instruction Cycles (which each take 1 microsecond to execute with a 4 MHz clock), up to a maximum time of about 60 ms (i.e. 60,000 Instruction Cycles). MODE 2 increases the clock to 16 MHz, but the maximum measurement period is unchanged, thus up to about 250,000 PIC instructions can be counted. The displayed result is still in us, which needs to be multiplied by 4 to give Instruction Cycles. MODE 3 also uses 16 MHz, but the displayed result is divided by 2.50 (with two decimal places) to give a direct indication of the execution time in ms (up to 255.99 ms at 4 MHz) or Instruction Cycles up to 250,000+. The loss of the lowest digit (units of microseconds or Instruction Cycles) is insignificant due to the interpreter variations.
The program uses only variables b22 - b27 (w11 - w13) but these can be reclaimed by using the system variables s_w2 - s_w6 instead. The sanity check "seed" is probably unnecessary now, but can be useful for evaluating commands such as PAUSE and WRITE. Almost any number of instructions can be inserted into the program (between the calls to "start" and "measure"), or even multiple nested calls to subroutines, etc.. Obviously, unconditional DO .. LOOPs cannot be analysed (unless they enclose a Conditional Exit of some type) but the despised "GOTO main" type of structure can be "unrolled" by jumping instead to the end of the test block. For this reason a "test N:" label is available at the END of each block. Most other instructions can be included and the sample code shows how a GOSUB and RETURN can be analysed individually, but some input / blocking commands may be unsuitable. There are also a few instructions that aren't directly determined by the SETFREQ value, for example READADC{10}, WRITE and READTEMP, etc.. Incidentally, WRITE is the "slowest" single instruction I've encountered so far, at around 10,000 PIC cycles (10ms at 4 MHz).
Well, that's just at the forum's 10,000 character limit again.
Cheers, Alan.
This is based on a program that I wrote in 2012 which became somewhat "lost" in a thread with a rather unmemorable title (at least for me). I've used the program many times over the years, so have now "tidied it up" and added a few more features. However, I won't repeat much of the detail from the original thread, but just point to post #12 of this thread. The program can estimate the execution time of almost any single instruction, simple algorithm, or through to quite large subroutines, etc. on any M2 PICaxe, by comparing the internal "Timer 1" values, immediately before and after execution of the instruction(s) under test. Thus, no external hardware is required, except for a powered M2 PICaxe connected to the Program Editor / Terminal Emulator.
But first a disclaimer: It's been discussed numerous times that PICaxe program instructions do not have an absolute execution time, because the interpreter "tokens" do not (necessarily) fit neatly within the program memory byte boundaries. This means that the slightest change to the program structure can alter the execution time of the component instructions. These variations occur at the Program Editing stage so the program itself cannot "investigate" the variations which might occur, and ultimately the Programmer/User must identify any inconsistencies. However, the same program, if run multiple times, appears to give exactly the same results, which suggests that the internal System Interrupts become synchronised to the program instructions (or vice versa).
Timer 1 is primarily used by the PICaxe Operating System to time the Servo pulses, so the program may disturb the operation of these (because it increases the timing period to 65 ms). The new program also pauses the Timer between reading its Low and High bytes, which seems to have eliminated some of the occasional inconsistencies with the original program. Normally, Timer 1 appears to "always" count through 20,000 cycles, but its period is 20 ms with a SETFREQ of only m4 or m16.
The new version includes three operating modes: MODE 1 gives a similar output to the original program, indicating the number of PIC Instruction Cycles (which each take 1 microsecond to execute with a 4 MHz clock), up to a maximum time of about 60 ms (i.e. 60,000 Instruction Cycles). MODE 2 increases the clock to 16 MHz, but the maximum measurement period is unchanged, thus up to about 250,000 PIC instructions can be counted. The displayed result is still in us, which needs to be multiplied by 4 to give Instruction Cycles. MODE 3 also uses 16 MHz, but the displayed result is divided by 2.50 (with two decimal places) to give a direct indication of the execution time in ms (up to 255.99 ms at 4 MHz) or Instruction Cycles up to 250,000+. The loss of the lowest digit (units of microseconds or Instruction Cycles) is insignificant due to the interpreter variations.
The program uses only variables b22 - b27 (w11 - w13) but these can be reclaimed by using the system variables s_w2 - s_w6 instead. The sanity check "seed" is probably unnecessary now, but can be useful for evaluating commands such as PAUSE and WRITE. Almost any number of instructions can be inserted into the program (between the calls to "start" and "measure"), or even multiple nested calls to subroutines, etc.. Obviously, unconditional DO .. LOOPs cannot be analysed (unless they enclose a Conditional Exit of some type) but the despised "GOTO main" type of structure can be "unrolled" by jumping instead to the end of the test block. For this reason a "test N:" label is available at the END of each block. Most other instructions can be included and the sample code shows how a GOSUB and RETURN can be analysed individually, but some input / blocking commands may be unsuitable. There are also a few instructions that aren't directly determined by the SETFREQ value, for example READADC{10}, WRITE and READTEMP, etc.. Incidentally, WRITE is the "slowest" single instruction I've encountered so far, at around 10,000 PIC cycles (10ms at 4 MHz).
Code:
; Program to Estimate the Execution speed of most M2 PICaxe Instructions
; AllyCat, 2012, Updated August 2019
#picaxe 08m2 ; Or any other M2 but *CANNOT USE THE SIMULATOR*
#no_data ; No data to load into EPROM
#terminal 4800 ; 4800 baud at setfreq m4 (*Also X2s require SFR changes*)
; *Select MODE here* ; MODE 1 = Number of PIC Instruction cycles (= time in us)
symbol MODE = 3 ; MODE 2 = Measure times with Setfreq M16 (up to 64,000 us)
; MODE 3 = Calculate 4MHz execution times up to 255.99ms
symbol TMR1L = $16 ; Timer 1 Low byte SFR address
symbol TMR1H = $17 ; Timer 1 High byte SFR address
symbol T1CON = $18 ; Control Register: Prescaler = %--nn---- (PS = 2^nn)
symbol seed = b22 ; or s_w3 "Dither" on start time to check timer results
symbol tempb = b23 ; or s_w4 Temporary byte for MODE3, etc.
symbol exec = w12 ; or s_w5 16-bit execution cycles or time
symbol nul = w13 ; or s_w6 Overhead for Call/Return,etc.with no instructions
main:
for seed = 0 to 256 step 32 ; Sanity check for timer handling (STEP optional)
seed = seed and 255 ; Allows use of S_W variable (optional)
nul = 0
sertxd(cr,lf,"Mode= ",#MODE)
sertxd(" | Time= ",#time,cr,lf) ; Optional
sertxd("Seed= ",#seed," | Nul=")
gosub start ; Start the NUL measurement
gosub measure ; Shows and Returns timer value in us or ms
nul = exec ; Store for subsequent calculations
gosub runtests ;* Update any of the target code as required *
sertxd(cr,lf,"Check=") ; Re-measure the NUL (or another) value
gosub start
gosub measure
if exec > 50 then
sertxd(" ***") ; Mark inaccurate nul result
endif
sertxd(cr,lf)
pause 5000
next seed ; Never finishes if STEP = 2^integer
sertxd(cr,lf,"Finished")
end
runtests:
sertxd(cr,lf,"Test1 IF.THEN true=") ; Report the first test
gosub start ;*--------------------------------------*
if seed = seed then ;* INSERT TARGET CODE BETWEEN ... *
endif ;* CALLS TO "start" and "measure" *
test1: ;* END of target (exit label if needed) *
gosub measure ;*--------------------------------------*
sertxd(cr,lf,"Test2 IF.THEN false=") ; Report the second test, etc.
gosub start
if seed <> seed then ; Equivalent to "IF (true) GOTO test2"
endif
test2:
gosub measure
sertxd(cr,lf,"Test3 PEEKSFR=")
gosub start
peeksfr T1CON,tempb
test3:
gosub measure
sertxd(cr,lf,"Test4 PULSOUT seed=")
gosub start
pulsout c.2,seed ; Very similar to PAUSEUS
test4:
gosub measure
sertxd(cr,lf,"Test5 GOSUB (only)=")
gosub start
gosub callandreturn ;* This test separates the CALL and RETURN times
test5:
gosub measure
sertxd(cr,lf,"Test6 CALL+RETURN=")
gosub start
call retn ; To return immediately
test6:
gosub measure
return
callandreturn: ;* This is a TEST TARGET subroutine being measured!
gosub measure
sertxd(cr,lf," Test5a RETURN=")
gosub start
retn:
RETURN
; REQUIRED SUBROUTINES
start: ; Setup the Mode and Reset Timer 0
tempb = MODE ; At least one variable is needed in IF.THEN
if tempb > 1 then
setfreq m16 ; For modes 2 and 3
pause 100 ;* 25 ms to allow 20 ms timer to update *
endif
gosub setup ; Only needed to initialise target code
peeksfr T1CON,tempb
pokesfr T1CON,0 ; Stop the timer
pokesfr TMR1H,0 ; Clear High byte
pokesfr TMR1L,seed ; Sanity check byte
pokesfr T1CON,tempb ; Restore the timer (1 / 33 at 4 / 16 MHz)
return
measure: ; Reads Timer 0, calculates and displays timed delay
pokesfr T1CON,0 ; Stop the timer to read both bytes
peeksfr TMR1L,tempb ; Read Low byte (S_W variables only words)
peeksfr TMR1H,exec ; Read High byte
pokesfr T1CON,1 ; Restart timer (can ignore frequency)
exec = exec * 256 + tempb ; Allows use of S_W variable
exec = exec - nul - seed ; Estimate execution time of target code
setfreq m4 ; Ensure serial comms are at default again
if exec > 64000 then ; Correctly display negative values (near zero)
sertxd(" -")
exec = - exec
else
sertxd(" +")
endif
tempb = MODE
if tempb < 3 then ; Check the MODE
sertxd (#exec," us ")
else ; Display in ms to 2 decimal places
tempb = exec ** 26214 / 100 ; *4/10 = 26214 / 65536 then /100
sertxd(#tempb,".") ; Units of ms
tempb = exec ** 26214 // 100 / 10
sertxd(#tempb) ; Tenths of ms
tempb = exec ** 26214 // 10
sertxd(#tempb," ms") ; Hundredths of ms
endif
return
setup: ; Initialise values required for the test targets (only)
return
#rem TERMINAL RESULT:
Mode= 3 | Time= 193
Seed= 96 | Nul= +3.59 ms
Test1 IF.THEN true= +0.73 ms
Test2 IF.THEN false= +1.20 ms
Test3 PEEKSFR= +0.58 ms
Test4 PULSOUT seed= +1.44 ms
Test5 GOSUB (only)= +0.87 ms
Test5a RETURN= +2.17 ms
Test6 CALL+RETURN= +3.05 ms
Check= -0.01 ms
#endrem
Well, that's just at the forum's 10,000 character limit again.
Cheers, Alan.