[Linuxptp-users] Improved accuracy with software timestamps under high CPU load

[Dylan D. <dh...@um...>]

Hi!

I was experimenting to see how far I could push PTP accuracy using software
timstamps. I have a simple test setup with a single master and a single slave,
configured to use the P2P delay mechanism. logSyncInterval on the master is set
to -8. Both systems have tickless kernel disabled (nohz=off). With both systems
idle I can reach around 2us rms offset and 15-20us peak offset. If I then fully
load all 4 cores of the slave (using the 'stress' program), after a brief spike
the accuracy of the synchronization actually *improves*, reaching 300-500ns rms
offset and around 3us peak offset. Removing the CPU load brings the offset back
to its original magnitude. In both cases the rms and max offset values are
consistent, with only occasional spikes. Interestingly, the reported delay under
load is 12us less than when unloaded.

These results are unintuitive, and I can't come up with a solid explanation for
them. Assuming the reported offsets are accurate (which may be a poor
assumption), my best guess is that somehow the 'stress' workload is forcing
ptp4l to be scheduled more consistently, but that's only speculation. Can
anybody shed some light on what's happening here?

I've attached the slave log for the test run below.

Thanks,
Dylan


ptp4l[8649.834]: port 1: get_ts_info not supported
ptp4l[8649.834]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[8649.834]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[8650.918]: port 1: new foreign master 0019b9.fffe.252000-1
ptp4l[8654.918]: selected best master clock 0019b9.fffe.252000
ptp4l[8654.918]: foreign master not using PTP timescale
ptp4l[8654.918]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[8656.840]: rms 734578 max 744561 freq +26416 +/-   0 delay 39708 +/-  24
ptp4l[8657.848]: rms 736520 max 743539 freq +26416 +/-   0 delay 39638 +/-   0
...
ptp4l[8801.938]: rms 945773 max 964402 freq +26416 +/-   0 delay 39709 +/-   0
ptp4l[8802.730]: port 1: UNCALIBRATED to SLAVE on MASTER_CLOCK_SELECTED
ptp4l[8802.946]: rms 836497 max 955345 freq +26150 +/- 548 delay 39709 +/-   0
ptp4l[8803.954]: rms 1783 max 12258 freq +25241 +/- 902 delay 39713 +/-   0
ptp4l[8804.961]: rms 2157 max 14819 freq +25446 +/- 1045 delay 39717 +/-   0

...
ptp4l[8855.342]: rms 2248 max 16992 freq +25950 +/- 1166 delay 39664 +/-   0
ptp4l[8856.350]: rms 2161 max 16421 freq +25903 +/- 1129 delay 39664 +/-   0
START CPU LOAD
ptp4l[8857.357]: rms 11941 max 23139 freq +22475 +/- 5440 delay 39743 +/-   0
ptp4l[8858.365]: rms 15882 max 21184 freq +17063 +/- 1244 delay 39743 +/-   0
ptp4l[8859.372]: rms 8949 max 12262 freq +20357 +/- 796 delay 39743 +/-   0
ptp4l[8860.380]: rms 4424 max 6615 freq +22570 +/- 580 delay 39619 +/-   0
ptp4l[8861.388]: rms 1683 max 3025 freq +23970 +/- 421 delay 39460 +/-   0
ptp4l[8862.395]: rms 3780 max 7212 freq +26205 +/- 1386 delay 34165 +/-   0
ptp4l[8863.403]: rms 7421 max 12901 freq +28606 +/- 1288 delay 28178 +/-   0
ptp4l[8864.410]: rms 6528 max 10496 freq +28518 +/- 400 delay 28178 +/-   0
ptp4l[8865.418]: rms 4527 max 5672 freq +27623 +/- 257 delay 27930 +/-   0
ptp4l[8866.426]: rms 3457 max 6476 freq +27161 +/- 279 delay 27592 +/-   0
ptp4l[8867.433]: rms 2612 max 4947 freq +26802 +/- 218 delay 27567 +/-   0
ptp4l[8868.441]: rms 1846 max 3771 freq +26454 +/- 206 delay 27567 +/-   0
ptp4l[8869.448]: rms 1467 max 4106 freq +26293 +/- 207 delay 27545 +/-   0
ptp4l[8870.456]: rms 1380 max 3813 freq +26274 +/- 234 delay 27545 +/-   0
ptp4l[8871.463]: rms 1086 max 3599 freq +26149 +/- 212 delay 27477 +/-   0
ptp4l[8872.471]: rms 1016 max 3528 freq +26143 +/- 196 delay 27389 +/-   0
ptp4l[8873.479]: rms  853 max 2890 freq +26082 +/- 177 delay 27359 +/-   0
ptp4l[8874.486]: rms  891 max 2639 freq +26124 +/- 182 delay 27359 +/-   0
ptp4l[8875.494]: rms  808 max 3244 freq +26071 +/- 230 delay 27359 +/-   0
ptp4l[8876.501]: rms 1039 max 11250 freq +26094 +/- 411 delay 27348 +/-   0
ptp4l[8877.509]: rms  815 max 4812 freq +26092 +/- 260 delay 27359 +/-   0
ptp4l[8878.517]: rms  720 max 3040 freq +26074 +/- 222 delay 27348 +/-   0
ptp4l[8879.524]: rms  635 max 3106 freq +26050 +/- 201 delay 27348 +/-   0
ptp4l[8880.532]: rms  875 max 8865 freq +26029 +/- 398 delay 27348 +/-   0
ptp4l[8881.539]: rms  538 max 2507 freq +26028 +/- 178 delay 27349 +/-   0
...
ptp4l[8948.041]: rms  414 max 2590 freq +26419 +/- 190 delay 27396 +/-   0
ptp4l[8949.049]: rms  478 max 2572 freq +26399 +/- 238 delay 27519 +/-   0
ptp4l[8950.056]: rms  329 max 2126 freq +26299 +/- 173 delay 27519 +/-   0
ptp4l[8951.064]: rms  329 max  836 freq +26360 +/- 169 delay 27519 +/-   0
ptp4l[8952.071]: rms  375 max 2201 freq +26392 +/- 185 delay 27442 +/-   0
END CPU LOAD
ptp4l[8953.079]: rms 18781 max 31000 freq +35948 +/- 3220 delay 27543 +/-   0
ptp4l[8954.087]: rms 11567 max 21944 freq +32929 +/- 1356 delay 27561 +/-   0
ptp4l[8955.094]: rms 6487 max 18632 freq +30427 +/- 1190 delay 27561 +/-   0
ptp4l[8956.102]: rms 3574 max 20490 freq +28809 +/- 1182 delay 27997 +/-   0
ptp4l[8957.109]: rms 3211 max 13653 freq +26883 +/- 1625 delay 33853 +/-   0
ptp4l[8958.117]: rms 6117 max 15778 freq +24339 +/- 1348 delay 39216 +/-   0
ptp4l[8959.125]: rms 6791 max 16738 freq +23659 +/- 990 delay 39338 +/-   0
ptp4l[8960.132]: rms 5012 max 22610 freq +24594 +/- 1199 delay 39424 +/-   0
ptp4l[8961.140]: rms 3755 max 25494 freq +25219 +/- 1130 delay 39424 +/-   0
ptp4l[8962.147]: rms 2528 max 13296 freq +25792 +/- 899 delay 39424 +/-   0
ptp4l[8963.155]: rms 2324 max 14095 freq +25982 +/- 970 delay 39573 +/-   0
ptp4l[8964.163]: rms 2215 max 19140 freq +26043 +/- 971 delay 39730 +/-   0
...
ptp4l[9004.467]: rms 2661 max 22221 freq +26836 +/- 1388 delay 39727 +/-   0
ptp4l[9005.474]: rms 1767 max 14313 freq +26741 +/- 926 delay 39731 +/-   0
ptp4l[9006.482]: rms 1540 max 10717 freq +26625 +/- 813 delay 39700 +/-   0
ptp4l[9007.490]: rms 1804 max 14455 freq +26692 +/- 951 delay 39748 +/-   0