Methodology of IPC benchmarking should be corrected

[JDuchniewicz]

In IPC benchmarks the benchmarking methodology may be introducing a big standard deviation because the samples are stored in memory instead of accumulated on the fly in one variable. This is done properly in early proc benchmarks.

Such benchmarking methodology has some benefits like being able to observe/plot the timeseries and clearly spot any outliers/patterns. However, computing the mean and standard deviation from such singular samples may be unnecessary adding the time to store a variable to memory on top of the actual measurement.

Since the official website uses the results of this benchmark, we should ensure the methodology is following the best practices. From what I understand the early proc results follow the proper methodology but on the website we use the results from the methodology which is subject to platform noise (and indeed sometimes the standard deviation is quite high).

Image courtesy of Gernot Heiser:

[lsf37]

So this all sounds good in theory (not trying to be sarcastic, I do actually agree), but there was a previous attempt at this in #33 and it did not in fact reduce the standard deviation much.

Has anything changed? What went wrong in the previous attempt?

[JDuchniewicz]

I will need to investigate why indeed the current early proc benchmarks are subject to big noise and sometimes give even worse stddev than the regular benchmarks. Surely something else is also introducing the noise - or the methodology of early processing is wrong.

[JDuchniewicz]

After extensive testing on various platforms, my conclusion is that we have usually better (sometimes much more sometimes just better) results when using early processing. @midnightveil updated the website CI actions to use the early processing variants of the measurements.

Providing an arbitrary table of results across different platforms as a proof, also attaching the logs from the runs. sel4bench manifest @ 79b58ded544d29b1e29e31b3790eb414ad42eb6b

Platform	Benchmark	Non-EP mean	Non-EP stddev	EP mean	EP stddev	Δmean (EP-NonEP)
imx8mm_evk	Consumer to producer	1531.26	625.02302	1318	8.626016651	-213.26
imx8mq_evk	Consumer to producer	1326.72	10.915258	1305	7.658528659	-21.72
jetson1	Consumer to producer	2144.86	24.03865934	2126	3.461154697	-18.86
maaxboard	Consumer to producer	1361.66	110.8211466	1305	7.658528659	-56.66
odroidc2	Consumer to producer	1309.96	8.53803017	1302	7.658528659	-7.96
odroidc4	Consumer to producer	1313.92	53.16742904	1306	4.465285602	-7.92
sabre	Consumer to producer	1693.32	17.03537736	1676	14.90377298	-17.32
zcu102_2	Consumer to producer	1329.6	22.67066791	1317	8.626016651	-12.6
imx8mm_evk	Process yield	776.9	748.8261791	502	0	-274.9
imx8mq_evk	Process yield	752.07	682.0294063	502	0	-250.07
jetson1	Process yield	941.56	22.73119158	905	25.74211657	-36.56
maaxboard	Process yield	576.15	201.7524486	502	0	-74.15
odroidc2	Process yield	507.86	15.95574688	502	0	-5.86
odroidc4	Process yield	474.15	66.66446966	467	0	-7.15
sabre	Process yield	617.34	5.414160259	625	5.461527518	7.66
zcu102_2	Process yield	504.77	14.36641707	502	0	-2.77
imx8mm_evk	Producer to consumer	1435.72	552.5819913	1338	139.6074672	-97.72
imx8mq_evk	Producer to consumer	1426.52	516.6822337	1326	141.9039629	-100.52
jetson1	Producer to consumer	2177.26	191.5500148	2158	205.7478643	-19.26
maaxboard	Producer to consumer	1369.88	247.2850953	1323	128.6779717	-46.88
odroidc2	Producer to consumer	1328.02	136.7478687	1322	135.9731366	-6.02
odroidc4	Producer to consumer	1328.04	133.013886	1327	145.3994498	-1.04
sabre	Producer to consumer	1767.68	326.5008673	1722	341.1419	-45.68
zcu102_2	Producer to consumer	1349.58	157.0123484	1337	140.938183	-12.58
imx8mm_evk	Signal to high prio thread	980.35	655.5038235	740	10.20843383	-240.35
imx8mq_evk	Signal to high prio thread	808.23	225.6224835	741	9.954441677	-67.23
jetson1	Signal to high prio thread	1217.8	36.66280971	1209	68.45251986	-8.8
maaxboard	Signal to high prio thread	782.25	124.4881642	741	9.932092662	-41.25
odroidc2	Signal to high prio thread	759.22	34.16892084	739	9.787644241	-20.22
odroidc4	Signal to high prio thread	732.28	6.18241233	733	4.857567251	0.72
sabre	Signal to high prio thread	853.88	72.27347055	913	137.6261588	59.12
zcu102_2	Signal to high prio thread	739	13.44198158	739	9.989893883	0
imx8mm_evk	Thread yield	796.31	765.2022971	502	0	-294.31
imx8mq_evk	Thread yield	752.15	682.2298185	502	0	-250.15
jetson1	Thread yield	894.05	45.03769465	873	33.46081683	-21.05
maaxboard	Thread yield	582.56	209.4595258	502	0	-80.56
odroidc2	Thread yield	508.52	17.06493836	511	0	2.48
odroidc4	Thread yield	468.94	5.132585542	467	0	-1.94
sabre	Thread yield	616.83	5.338066082	618	5.649707242	1.17
zcu102_2	Thread yield	503.54	5.320059239	502	0	-1.54

Closing this because it turns out that IPC is already robust enough and early processing would not change anything there. I did open two PRs due to this investigation: #67 and #68

[lsf37]

Just for posterity: according to Indan's investigation while he was adjusting sel4bench for the FPU changes, the early processing method did use FPU (SIMD) instructions. In earlier benchmark results, this would have introduced all kinds of problems/noise, because the kernel would trap and context switch the FPU when that instruction was run and then attempt to unload the FPU again after 64 context switches.

Some of this must also have applied to other benchmarks that inadvertently used the FPU, although most of that was only during initialisation.

In any case, that source of noise should now be gone.

[JDuchniewicz]

That would explain the previous noisiness, as cited in #33

Note: results above were obtained on the sel4bench version without Indan's changes (#62). The noisiness should go down even more after this.
cc @midnightveil

[gernotheiser]

OK, great progress.
While we're at fixing methodology, how about:

1. turn off all optimisation (i.e. compile with -O0) in the benchmarking rig (which would have probably stopped is FPU issue already)
2. stop this nonsensical printing of standard deviations to 10(!) digits
3. generally not print fractions of cycles?

[Indanz]

1. turn off all optimisation (i.e. compile with -O0) in the benchmarking rig (which would have probably stopped is FPU issue already)

Partially agreed, but please do O2 or at least O1. O0 is actually unrealistically horribly bloated and unreadable when trying to debug on an assembly level.

The more tricky to avoid SIMD usages are in libc, especially memset() or memcpy.

2. stop this nonsensical printing of standard deviations to 10(!) digits

3. generally not print fractions of cycles?

Agreed with these.

[Indanz]

I find the zero EP stddev highly suspicious, especially for imx8mq_evk. How sure are we that they are correct and not overflowing during the calculation?

[gernotheiser]

Partially agreed, but please do O2 or at least O1. O0 is actually unrealistically horribly bloated and unreadable when trying to debug on an assembly level.

Why would you want to debug on assembly level a simple loop that invokes a syscall, reads the cycle counter and multiply&adds a few integers?

You want that rig to do exactly what you write without the compiler second-guessing.

The more tricky to avoid SIMD usages are in libc, especially memset() or memcpy.

... none of which should be in the benchmarking loop.

[gernotheiser]

I find the zero EP stddev highly suspicious

I don't. This should be a completely deterministic operation (warmup notwithstanding) so my expectation is to see stddevs that are mostly zeros and ones

[Indanz]

Partially agreed, but please do O2 or at least O1. O0 is actually unrealistically horribly bloated and unreadable when trying to debug on an assembly level.

Why would you want to debug on assembly level a simple loop that invokes a syscall, reads the cycle counter and multiply&adds a few integers?

The compiler optimisation applies to all code, not just that bit. Also, if you want so much control over that bit of code, write it all in assembly.

You want that rig to do exactly what you write without the compiler second-guessing.

I think it would be fairer to use the libsel4 API instead of hand-coded assembly. The *WithMRs functions should be good enough.

The more tricky to avoid SIMD usages are in libc, especially memset() or memcpy.

... none of which should be in the benchmarking loop.

Again, you don't have such fine-grained control over compiler optimisations. At best it is at a whole .C file level.

But the main problem was that code outside the benchmark timing section used FPU (in the libplatformsupport IRQ driver), while I disabled the FPU for the whole task. The work around was to enable and disable the FPU for each benchmark iteration.

I don't. This should be a completely deterministic operation (warmup notwithstanding) so my expectation is to see stddevs that are mostly zeros and ones

Sure, but not if your baseline was a stddev of around 700! Then it just reeks of overflow. Edit: But perhaps in this case it's more likely that there is a bug triggered by the no-early-proc code.

[Indanz]

Just for posterity: according to Indan's investigation while he was adjusting sel4bench for the FPU changes, the early processing method did use FPU (SIMD) instructions.

Btw, I think I drew the wrong conclusion when looking at the code out of context. I assumed early processing would do the processing during the benchmark run itself, but that's not what it apparently does: It just adds all measurements together and then has a post processing step that does the final calculations with floating points.

But it also accumulates sample * sample, which can quickly overflow for large numbers. That said, the tests are using very low N_RUNS, only 100 or 50, so with that in mind it does seem less likely. But with such low sample numbers there should really be not much difference in test results between early processing and no early processing. Perhaps zero the result arrays so they're cache hot before running the benchmark?

There is something very weird going on with the imx8mm_evk and imx8mq_evk no-early-processing results, it must be a bug somewhere (writing to uncached memory somewhere?).

[JDuchniewicz]

There is something very weird going on with the imx8mm_evk and imx8mq_evk no-early-processing results, it must be a bug somewhere (writing to uncached memory somewhere?).

In general I observed a lot of per-architecture dependent behavior on no-early-processing. That's why I strongly believe that what @midnightveil merged in seL4/ci-actions#428 and me in seL4/ci-actions#429 are necessary to reflect the results accurately.

Copying a message from a private conversation:

Why I think the non-early processing allows for too much platform-related noise

Since in the non-early processing benchmarks we have to write immediate results to memory we invoke a lot of platform dependent intricacies like cache size/DDR performance if we have to store in memory. We even encounter in-order vs out-of-order processor differences where last samples suffer worse performance due to ending of execution of given "similar" instructions on out-of-order processors (Cortex-A15 and Cortex-A57).

Moreover, we can see recurring patterns of every 8th sample triggering a penalty on saving (especially visible for A53 for some reason? - maybe slower memory?). This will be avoided with early-processing always because we don't store anything in memory and rely on storing the accumulated values in registers.

So we definitely have platform-specific noise present in non-EP variants.