Skip to content

Commit 38010c1

Browse files
peter-mitsisaescolar
peter-mitsis
authored and
aescolar
committed
test: latency_measure: Update sample output
Updates the sample output in the latency_measure benchmark's README file. Signed-off-by: Peter Mitsis <[email protected]>
1 parent 7103b0c commit 38010c1

File tree

1 file changed

+121
-73
lines changed

1 file changed

+121
-73
lines changed

‎tests/benchmarks/latency_measure/README.rst

Lines changed: 121 additions & 73 deletions
Original file line numberDiff line numberDiff line change
@@ -8,14 +8,18 @@ including:
88
* Context switch time between cooperative threads using k_yield
99
* Time to switch from ISR back to interrupted thread
1010
* Time from ISR to executing a different thread (rescheduled)
11-
* Times to signal a semaphore then test that semaphore
12-
* Times to signal a semaphore then test that semaphore with a context switch
11+
* Time to signal a semaphore then test that semaphore
12+
* Time to signal a semaphore then test that semaphore with a context switch
1313
* Times to lock a mutex then unlock that mutex
1414
* Time it takes to create a new thread (without starting it)
1515
* Time it takes to start a newly created thread
1616
* Time it takes to suspend a thread
1717
* Time it takes to resume a suspended thread
1818
* Time it takes to abort a thread
19+
* Time it takes to add data to a FIFO/LIFO
20+
* Time it takes to retrieve data from a FIFO/LIFO
21+
* Time it takes to wait on a FIFO/LIFO (and context switch)
22+
* Time it takes to wake and switch to a thread waiting on a FIFO/LIFO
1923
* Measure average time to alloc memory from heap then free that memory
2024

2125
When userspace is enabled using the prj_user.conf configuration file, this benchmark will
@@ -29,81 +33,125 @@ threads:
2933

3034
Sample output of the benchmark (without userspace enabled)::
3135

32-
*** Booting Zephyr OS build v3.5.0-rc1-139-gdab69aeed11d ***
33-
START - Time Measurement
34-
Timing results: Clock frequency: 120 MHz
35-
Preemptive threads ctx switch via k_yield (K -> K) : 519 cycles , 4325 ns :
36-
Cooperative threads ctx switch via k_yield (K -> K) : 519 cycles , 4325 ns :
37-
Switch from ISR back to interrupted thread : 508 cycles , 4241 ns :
38-
Switch from ISR to another thread (kernel) : 554 cycles , 4616 ns :
39-
Create kernel thread from kernel thread : 396 cycles , 3308 ns :
40-
Start kernel thread from kernel thread : 603 cycles , 5033 ns :
41-
Suspend kernel thread from kernel thread : 599 cycles , 4992 ns :
42-
Resume kernel thread from kernel thread : 547 cycles , 4558 ns :
43-
Abort kernel thread from kernel thread : 339 cycles , 2825 ns :
44-
Give a semaphore (no waiters) from kernel thread : 134 cycles , 1116 ns :
45-
Take a semaphore (no blocking) from kernel thread : 53 cycles , 441 ns :
46-
Take a semaphore (context switch K -> K) : 689 cycles , 5742 ns :
47-
Give a semaphore (context switch K -> K) : 789 cycles , 6575 ns :
48-
Lock a mutex from kernel thread : 94 cycles , 783 ns :
49-
Unlock a mutex from kernel thread : 24 cycles , 200 ns :
50-
Average time for heap malloc : 620 cycles , 5166 ns :
51-
Average time for heap free : 431 cycles , 3591 ns :
36+
*** Booting Zephyr OS build zephyr-v3.5.0-3537-g5dbe0ce2622d ***
37+
THREAD yield.preemptive.ctx.(K -> K) : 344 cycles , 2866 ns :
38+
THREAD yield.cooperative.ctx.(K -> K) : 344 cycles , 2867 ns :
39+
ISR resume.interrupted.thread.kernel : 498 cycles , 4158 ns :
40+
ISR resume.different.thread.kernel : 383 cycles , 3199 ns :
41+
THREAD create.kernel.from.kernel : 401 cycles , 3349 ns :
42+
THREAD start.kernel.from.kernel : 418 cycles , 3491 ns :
43+
THREAD suspend.kernel.from.kernel : 433 cycles , 3616 ns :
44+
THREAD resume.kernel.from.kernel : 351 cycles , 2933 ns :
45+
THREAD abort.kernel.from.kernel : 349 cycles , 2909 ns :
46+
FIFO put.immediate.kernel : 294 cycles , 2450 ns :
47+
FIFO get.immediate.kernel : 135 cycles , 1133 ns :
48+
FIFO put.alloc.immediate.kernel : 906 cycles , 7550 ns :
49+
FIFO get.free.immediate.kernel : 570 cycles , 4750 ns :
50+
FIFO get.blocking.(K -> K) : 545 cycles , 4542 ns :
51+
FIFO put.wake+ctx.(K -> K) : 675 cycles , 5625 ns :
52+
FIFO get.free.blocking.(K -> K) : 555 cycles , 4625 ns :
53+
FIFO put.alloc.wake+ctx.(K -> K) : 670 cycles , 5583 ns :
54+
LIFO put.immediate.kernel : 282 cycles , 2350 ns :
55+
LIFO get.immediate.kernel : 135 cycles , 1133 ns :
56+
LIFO put.alloc.immediate.kernel : 903 cycles , 7526 ns :
57+
LIFO get.free.immediate.kernel : 570 cycles , 4750 ns :
58+
LIFO get.blocking.(K -> K) : 542 cycles , 4524 ns :
59+
LIFO put.wake+ctx.(K -> K) : 670 cycles , 5584 ns :
60+
LIFO get.free.blocking.(K -> K) : 547 cycles , 4558 ns :
61+
LIFO put.alloc.wake+ctx.(K -> K) : 670 cycles , 5583 ns :
62+
SEMAPHORE give.immediate.kernel : 165 cycles , 1375 ns :
63+
SEMAPHORE take.immediate.kernel : 69 cycles , 575 ns :
64+
SEMAPHORE take.blocking.(K -> K) : 489 cycles , 4075 ns :
65+
SEMAPHORE give.wake+ctx.(K -> K) : 604 cycles , 5033 ns :
66+
MUTEX lock.immediate.recursive.kernel : 115 cycles , 958 ns :
67+
MUTEX unlock.immediate.recursive.kernel : 40 cycles , 333 ns :
68+
HEAP malloc.immediate : 615 cycles , 5125 ns :
69+
HEAP free.immediate : 431 cycles , 3591 ns :
5270
===================================================================
5371
PROJECT EXECUTION SUCCESSFUL
5472

5573
Sample output of the benchmark (with userspace enabled)::
5674

57-
*** Booting Zephyr OS build v3.5.0-rc1-139-gdab69aeed11d ***
58-
START - Time Measurement
59-
Timing results: Clock frequency: 120 MHz
60-
Preemptive threads ctx switch via k_yield (K -> K) : 1195 cycles , 9958 ns :
61-
Preemptive threads ctx switch via k_yield (U -> U) : 1485 cycles , 12379 ns :
62-
Preemptive threads ctx switch via k_yield (K -> U) : 1390 cycles , 11587 ns :
63-
Preemptive threads ctx switch via k_yield (U -> K) : 1289 cycles , 10749 ns :
64-
Cooperative threads ctx switch via k_yield (K -> K) : 1185 cycles , 9875 ns :
65-
Cooperative threads ctx switch via k_yield (U -> U) : 1475 cycles , 12295 ns :
66-
Cooperative threads ctx switch via k_yield (K -> U) : 1380 cycles , 11504 ns :
67-
Cooperative threads ctx switch via k_yield (U -> K) : 1280 cycles , 10666 ns :
68-
Switch from ISR back to interrupted thread : 1130 cycles , 9416 ns :
69-
Switch from ISR to another thread (kernel) : 1184 cycles , 9874 ns :
70-
Switch from ISR to another thread (user) : 1390 cycles , 11583 ns :
71-
Create kernel thread from kernel thread : 985 cycles , 8208 ns :
72-
Start kernel thread from kernel thread : 1275 cycles , 10625 ns :
73-
Suspend kernel thread from kernel thread : 1220 cycles , 10167 ns :
74-
Resume kernel thread from kernel thread : 1193 cycles , 9942 ns :
75-
Abort kernel thread from kernel thread : 2555 cycles , 21292 ns :
76-
Create user thread from kernel thread : 849 cycles , 7083 ns :
77-
Start user thread from kernel thread : 6715 cycles , 55960 ns :
78-
Suspend user thread from kernel thread : 1585 cycles , 13208 ns :
79-
Resume user thread from kernel thread : 1383 cycles , 11525 ns :
80-
Abort user thread from kernel thread : 2420 cycles , 20167 ns :
81-
Create user thread from user thread : 2110 cycles , 17584 ns :
82-
Start user thread from user thread : 7070 cycles , 58919 ns :
83-
Suspend user thread from user thread : 1784 cycles , 14874 ns :
84-
Resume user thread from user thread : 1740 cycles , 14502 ns :
85-
Abort user thread from user thread : 3000 cycles , 25000 ns :
86-
Start kernel thread from user thread : 1630 cycles , 13583 ns :
87-
Suspend kernel thread from user thread : 1420 cycles , 11833 ns :
88-
Resume kernel thread from user thread : 1550 cycles , 12917 ns :
89-
Abort kernel thread from user thread : 3135 cycles , 26125 ns :
90-
Give a semaphore (no waiters) from kernel thread : 160 cycles , 1333 ns :
91-
Take a semaphore (no blocking) from kernel thread : 95 cycles , 791 ns :
92-
Give a semaphore (no waiters) from user thread : 380 cycles , 3166 ns :
93-
Take a semaphore (no blocking) from user thread : 315 cycles , 2625 ns :
94-
Take a semaphore (context switch K -> K) : 1340 cycles , 11167 ns :
95-
Give a semaphore (context switch K -> K) : 1460 cycles , 12167 ns :
96-
Take a semaphore (context switch K -> U) : 1540 cycles , 12838 ns :
97-
Give a semaphore (context switch U -> K) : 1800 cycles , 15000 ns :
98-
Take a semaphore (context switch U -> K) : 1690 cycles , 14084 ns :
99-
Give a semaphore (context switch K -> U) : 1650 cycles , 13750 ns :
100-
Take a semaphore (context switch U -> U) : 1890 cycles , 15756 ns :
101-
Give a semaphore (context switch U -> U) : 1990 cycles , 16583 ns :
102-
Lock a mutex from kernel thread : 105 cycles , 875 ns :
103-
Unlock a mutex from kernel thread : 17 cycles , 141 ns :
104-
Lock a mutex from user thread : 330 cycles , 2750 ns :
105-
Unlock a mutex from user thread : 255 cycles , 2125 ns :
106-
Average time for heap malloc : 606 cycles , 5058 ns :
107-
Average time for heap free : 422 cycles , 3516 ns :
75+
*** Booting Zephyr OS build zephyr-v3.5.0-3537-g5dbe0ce2622d ***
76+
THREAD yield.preemptive.ctx.(K -> K) : 990 cycles , 8250 ns :
77+
THREAD yield.preemptive.ctx.(U -> U) : 1285 cycles , 10712 ns :
78+
THREAD yield.preemptive.ctx.(K -> U) : 1178 cycles , 9817 ns :
79+
THREAD yield.preemptive.ctx.(U -> K) : 1097 cycles , 9145 ns :
80+
THREAD yield.cooperative.ctx.(K -> K) : 990 cycles , 8250 ns :
81+
THREAD yield.cooperative.ctx.(U -> U) : 1285 cycles , 10712 ns :
82+
THREAD yield.cooperative.ctx.(K -> U) : 1178 cycles , 9817 ns :
83+
THREAD yield.cooperative.ctx.(U -> K) : 1097 cycles , 9146 ns :
84+
ISR resume.interrupted.thread.kernel : 1120 cycles , 9333 ns :
85+
ISR resume.different.thread.kernel : 1010 cycles , 8417 ns :
86+
ISR resume.different.thread.user : 1207 cycles , 10062 ns :
87+
THREAD create.kernel.from.kernel : 955 cycles , 7958 ns :
88+
THREAD start.kernel.from.kernel : 1095 cycles , 9126 ns :
89+
THREAD suspend.kernel.from.kernel : 1064 cycles , 8874 ns :
90+
THREAD resume.kernel.from.kernel : 999 cycles , 8333 ns :
91+
THREAD abort.kernel.from.kernel : 2280 cycles , 19000 ns :
92+
THREAD create.user.from.kernel : 822 cycles , 6855 ns :
93+
THREAD start.user.from.kernel : 6572 cycles , 54774 ns :
94+
THREAD suspend.user.from.kernel : 1422 cycles , 11857 ns :
95+
THREAD resume.user.from.kernel : 1177 cycles , 9812 ns :
96+
THREAD abort.user.from.kernel : 2147 cycles , 17897 ns :
97+
THREAD create.user.from.user : 2105 cycles , 17542 ns :
98+
THREAD start.user.from.user : 6960 cycles , 58002 ns :
99+
THREAD suspend user.from.user : 1610 cycles , 13417 ns :
100+
THREAD resume user.from.user : 1565 cycles , 13042 ns :
101+
THREAD abort user.from.user : 2780 cycles , 23167 ns :
102+
THREAD start.kernel.from.user : 1482 cycles , 12353 ns :
103+
THREAD suspend.kernel.from.user : 1252 cycles , 10437 ns :
104+
THREAD resume.kernel.from.user : 1387 cycles , 11564 ns :
105+
THREAD abort.kernel.from.user : 2912 cycles , 24272 ns :
106+
FIFO put.immediate.kernel : 314 cycles , 2624 ns :
107+
FIFO get.immediate.kernel : 215 cycles , 1792 ns :
108+
FIFO put.alloc.immediate.kernel : 1025 cycles , 8541 ns :
109+
FIFO get.free.immediate.kernel : 655 cycles , 5458 ns :
110+
FIFO put.alloc.immediate.user : 1740 cycles , 14500 ns :
111+
FIFO get.free.immediate.user : 1410 cycles , 11751 ns :
112+
FIFO get.blocking.(K -> K) : 1249 cycles , 10416 ns :
113+
FIFO put.wake+ctx.(K -> K) : 1320 cycles , 11000 ns :
114+
FIFO get.free.blocking.(K -> K) : 1235 cycles , 10292 ns :
115+
FIFO put.alloc.wake+ctx.(K -> K) : 1355 cycles , 11292 ns :
116+
FIFO get.free.blocking.(U -> K) : 1750 cycles , 14584 ns :
117+
FIFO put.alloc.wake+ctx.(K -> U) : 1680 cycles , 14001 ns :
118+
FIFO get.free.blocking.(K -> U) : 1555 cycles , 12959 ns :
119+
FIFO put.alloc.wake+ctx.(U -> K) : 1845 cycles , 15375 ns :
120+
FIFO get.free.blocking.(U -> U) : 2070 cycles , 17251 ns :
121+
FIFO put.alloc.wake+ctx.(U -> U) : 2170 cycles , 18084 ns :
122+
LIFO put.immediate.kernel : 299 cycles , 2499 ns :
123+
LIFO get.immediate.kernel : 204 cycles , 1708 ns :
124+
LIFO put.alloc.immediate.kernel : 1015 cycles , 8459 ns :
125+
LIFO get.free.immediate.kernel : 645 cycles , 5375 ns :
126+
LIFO put.alloc.immediate.user : 1760 cycles , 14668 ns :
127+
LIFO get.free.immediate.user : 1400 cycles , 11667 ns :
128+
LIFO get.blocking.(K -> K) : 1234 cycles , 10291 ns :
129+
LIFO put.wake+ctx.(K -> K) : 1315 cycles , 10959 ns :
130+
LIFO get.free.blocking.(K -> K) : 1230 cycles , 10251 ns :
131+
LIFO put.alloc.wake+ctx.(K -> K) : 1345 cycles , 11208 ns :
132+
LIFO get.free.blocking.(U -> K) : 1745 cycles , 14544 ns :
133+
LIFO put.alloc.wake+ctx.(K -> U) : 1680 cycles , 14000 ns :
134+
LIFO get.free.blocking.(K -> U) : 1555 cycles , 12958 ns :
135+
LIFO put.alloc.wake+ctx.(U -> K) : 1855 cycles , 15459 ns :
136+
LIFO get.free.blocking.(U -> U) : 2070 cycles , 17251 ns :
137+
LIFO put.alloc.wake+ctx.(U -> U) : 2190 cycles , 18251 ns :
138+
SEMAPHORE give.immediate.kernel : 210 cycles , 1750 ns :
139+
SEMAPHORE take.immediate.kernel : 145 cycles , 1208 ns :
140+
SEMAPHORE give.immediate.user : 715 cycles , 5959 ns :
141+
SEMAPHORE take.immediate.user : 660 cycles , 5500 ns :
142+
SEMAPHORE take.blocking.(K -> K) : 1150 cycles , 9584 ns :
143+
SEMAPHORE give.wake+ctx.(K -> K) : 1279 cycles , 10666 ns :
144+
SEMAPHORE take.blocking.(K -> U) : 1343 cycles , 11192 ns :
145+
SEMAPHORE give.wake+ctx.(U -> K) : 1637 cycles , 13645 ns :
146+
SEMAPHORE take.blocking.(U -> K) : 1522 cycles , 12688 ns :
147+
SEMAPHORE give.wake+ctx.(K -> U) : 1472 cycles , 12270 ns :
148+
SEMAPHORE take.blocking.(U -> U) : 1715 cycles , 14296 ns :
149+
SEMAPHORE give.wake+ctx.(U -> U) : 1830 cycles , 15250 ns :
150+
MUTEX lock.immediate.recursive.kernel : 150 cycles , 1250 ns :
151+
MUTEX unlock.immediate.recursive.kernel : 57 cycles , 475 ns :
152+
MUTEX lock.immediate.recursive.user : 670 cycles , 5583 ns :
153+
MUTEX unlock.immediate.recursive.user : 595 cycles , 4959 ns :
154+
HEAP malloc.immediate : 629 cycles , 5241 ns :
155+
HEAP free.immediate : 414 cycles , 3450 ns :
108156
===================================================================
109157
PROJECT EXECUTION SUCCESSFUL

0 commit comments

Comments
 (0)