Artifact
62489deafddeca9deef5382c608397fcfa4f7ece:
Attachment "event-perf-test-diff.diff" to
ticket [0520d17284]
added by
sebres
2017-05-16 14:59:20.
% # after idle + after cancel
% after cancel [after idle {set foo bar}]
-0.954918 �s/# 508978 # 1047210 #/sec 486.032 nett-ms
+0.344879 �s/# 1328072 # 2899568 #/sec 458.024 nett-ms
% # after 0 + after cancel
% after cancel [after 0 {set foo bar}]
-1.087641 �s/# 448397 # 919420 #/sec 487.695 nett-ms
+0.346915 �s/# 1320929 # 2882551 #/sec 458.250 nett-ms
% # after idle + update idletasks
% after idle {set foo bar}; update idletasks
-4.081463 �s/# 121687 # 245010 #/sec 496.661 nett-ms
+0.647053 �s/# 736747 # 1545469 #/sec 476.714 nett-ms
% # after idle + update
% after idle {set foo bar}; update
-3.981399 �s/# 124725 # 251167 #/sec 496.580 nett-ms
+0.705721 �s/# 678126 # 1416989 #/sec 478.568 nett-ms
% # immediate: after 0 + update
% after 0 {set foo bar}; update
-4.608608 �s/# 107851 # 216985 #/sec 497.043 nett-ms
+0.697434 �s/# 685833 # 1433828 #/sec 478.323 nett-ms
% # delayed: after 1 + update
% after 1 {set foo bar}; update
-5.653049 �s/# 88021 # 176895 #/sec 497.587 nett-ms
+0.743475 �s/# 645094 # 1345035 #/sec 479.611 nett-ms
% # empty update:
% update
-1.475875 �s/# 332598 # 677564 #/sec 490.873 nett-ms
+0.151506 �s/# 2730558 # 6600381 #/sec 413.697 nett-ms
% # empty update idle tasks:
% update idletasks
-1.462542 �s/# 335574 # 683741 #/sec 490.791 nett-ms
+0.130797 �s/# 3078751 # 7645423 #/sec 402.692 nett-ms
********************************************************************************
-Total 8 cases in 4.01 sec. (3.94 nett-sec.):
-23.305495 �s/# 2067831 # 524396.046 #/sec 3943.262 nett-ms
+Total 8 cases in 4.02 sec. (3.65 nett-sec.):
+3.767780 �s/# 11204110 # 3073088.822 #/sec 3645.879 nett-ms
Average:
-2.913187 �s/# 258478 # 524394 #/sec 492.908 nett-ms
+0.470973 �s/# 1400513 # 3073086 #/sec 455.735 nett-ms
Min:
-0.954918 �s/# 508978 # 1047210 #/sec 486.032 nett-ms
+0.130797 �s/# 3078751 # 7645423 #/sec 402.692 nett-ms
Max:
-5.653049 �s/# 88021 # 176895 #/sec 497.587 nett-ms
+0.743475 �s/# 645094 # 1345035 #/sec 479.611 nett-ms
+********************************************************************************
+
+% # conditional update pure idle only (without window):
+% update -idle
+
+0.095864 �s/# 3922503 # 10431495 #/sec 376.025 nett-ms
+
+% # conditional update without idle events:
+% update -noidle
+
+0.151528 �s/# 2730240 # 6599453 #/sec 413.707 nett-ms
+
+% # conditional update timers only:
+% update -timer
+
+0.117460 �s/# 3354217 # 8513543 #/sec 393.986 nett-ms
+
+% # conditional update AIO only:
+% update -async
+
+0.101165 �s/# 3765861 # 9884798 #/sec 380.975 nett-ms
+
+% # conditional vwait with zero timeout: pure idle only (without window):
+% vwait -idle 0 x
+0
+0.575099 �s/# 824122 # 1738830 #/sec 473.952 nett-ms
+
+% # conditional vwait with zero timeout: without idle events:
+% vwait -noidle 0 x
+0
+0.651450 �s/# 732004 # 1535037 #/sec 476.864 nett-ms
+
+% # conditional vwait with zero timeout: timers only:
+% vwait -timer 0 x
+0
+0.608585 �s/# 781017 # 1643156 #/sec 475.315 nett-ms
+
+% # conditional vwait with zero timeout: AIO only:
+% vwait -async 0 x
+0
+0.588142 �s/# 806779 # 1700268 #/sec 474.501 nett-ms
+
+********************************************************************************
+Total 8 cases in 4.00 sec. (3.47 nett-sec.):
+2.889293 �s/# 16916743 # 4881719.031 #/sec 3465.325 nett-ms
+Average:
+0.361162 �s/# 2114592 # 4881713 #/sec 433.166 nett-ms
+Min:
+0.095864 �s/# 3922503 # 10431495 #/sec 376.025 nett-ms
+Max:
+0.651450 �s/# 732004 # 1535037 #/sec 476.864 nett-ms
********************************************************************************
% # in-between important event by amount of idle events:
% time {after idle {after 30}} 10; after 1 {set important 1}; vwait important;
-312082.0 �s/# 2 # 3.204 #/sec 624.164 nett-ms
+30473.9 �s/# 17 # 32.815 #/sec 518.056 nett-ms
% cleanup {foreach i [after info] {after cancel $i}}
% # in-between important event (of new generation) by amount of idle events:
% time {after idle {after 30}} 10; after 1 {after 0 {set important 1}}; vwait important;
-311908.5 �s/# 2 # 3.206 #/sec 623.817 nett-ms
+30849.2 �s/# 17 # 32.416 #/sec 524.437 nett-ms
% cleanup {foreach i [after info] {after cancel $i}}
********************************************************************************
-Total 2 cases in 1.88 sec. (1.25 nett-sec.):
-623990.500000 �s/# 4 # 3.205 #/sec 1247.981 nett-ms
+Total 2 cases in 1.10 sec. (1.04 nett-sec.):
+61323.100000 �s/# 34 # 32.614 #/sec 1042.493 nett-ms
Average:
-311995.250000 �s/# 2 # 3 #/sec 623.991 nett-ms
+30661.550000 �s/# 17 # 33 #/sec 521.246 nett-ms
Min:
-311908.5 �s/# 2 # 3.206 #/sec 623.817 nett-ms
+30473.9 �s/# 17 # 32.815 #/sec 518.056 nett-ms
Max:
-312082.0 �s/# 2 # 3.204 #/sec 624.164 nett-ms
+30849.2 �s/# 17 # 32.416 #/sec 524.437 nett-ms
********************************************************************************
*** 10000 events ***
% # update / after idle:
% setup {puts [time {after idle {set foo bar}} 10000]}
-0.8255515519028328 microseconds per iteration
+0.21706976032508818 microseconds per iteration
% update; # 10000 idle-events
-234843.0 �s/# 1 # 4.258 #/sec 234.843 nett-ms
+2897.00 �s/# 1 # 345.18 #/sec 2.897 nett-ms
% # update idletasks / after idle:
% setup {puts [time {after idle {set foo bar}} 10000]}
-0.8497381337389665 microseconds per iteration
+0.1958664041000426 microseconds per iteration
% update idletasks; # 10000 idle-events
-206202.0 �s/# 1 # 4.850 #/sec 206.202 nett-ms
+3746.00 �s/# 1 # 266.95 #/sec 3.746 nett-ms
% # update / after 0:
% setup {puts [time {after 0 {set foo bar}} 10000]}
-21.61478473781777 microseconds per iteration
+0.21453562244040045 microseconds per iteration
% update; # 10000 timer-events
-235198.0 �s/# 1 # 4.252 #/sec 235.198 nett-ms
+2363.00 �s/# 1 # 423.19 #/sec 2.363 nett-ms
% # update / after 1:
% setup {puts [time {after 1 {set foo bar}} 10000]; after 1}
-22.72611647218495 microseconds per iteration
+0.3867286878201955 microseconds per iteration
% update; # 10000 timer-events
-206160.0 �s/# 1 # 4.851 #/sec 206.160 nett-ms
+2463.00 �s/# 1 # 406.01 #/sec 2.463 nett-ms
% # cancel forwards "after idle" / 10000 idle-events in queue:
% setup {set i 0; time {set ev([incr i]) [after idle {set foo bar}]} 10000}
-1.229890894136871 microseconds per iteration
+0.5918334680061884 microseconds per iteration
% set i 0; time {after cancel $ev([incr i])} 10000
-1035573 �s/# 1 # 0.966 #/sec 1035.573 nett-ms
+3887.00 �s/# 1 # 257.27 #/sec 3.887 nett-ms
% cleanup {update}
% # cancel backwards "after idle" / 10000 idle-events in queue:
% setup {set i 0; time {set ev([incr i]) [after idle {set foo bar}]} 10000}
-1.1445321484260598 microseconds per iteration
+0.5243740759619058 microseconds per iteration
% incr i; time {after cancel $ev([incr i -1])} 10000
-509716.0 �s/# 1 # 1.962 #/sec 509.716 nett-ms
+4249.00 �s/# 1 # 235.35 #/sec 4.249 nett-ms
% cleanup {update}
% # cancel forwards "after 0" / 10000 timer-events in queue:
% setup {set i 0; time {set ev([incr i]) [after 0 {set foo bar}]} 10000}
-24.11735817087852 microseconds per iteration
+0.5420809634599771 microseconds per iteration
% set i 0; time {after cancel $ev([incr i])} 10000
-700844.0 �s/# 1 # 1.427 #/sec 700.844 nett-ms
+5026.00 �s/# 1 # 198.97 #/sec 5.026 nett-ms
% cleanup {update}
% # cancel backwards "after 0" / 10000 timer-events in queue:
% setup {set i 0; time {set ev([incr i]) [after 0 {set foo bar}]} 10000}
-27.022506672962447 microseconds per iteration
+0.5284479431942519 microseconds per iteration
% incr i; time {after cancel $ev([incr i -1])} 10000
-522305.0 �s/# 1 # 1.915 #/sec 522.305 nett-ms
+4014.00 �s/# 1 # 249.13 #/sec 4.014 nett-ms
% cleanup {update}
% # end 10000 events.
********************************************************************************
-Total 8 cases in 4.67 sec. (3.65 nett-sec.):
-3650841.000000 �s/# 8 # 2.191 #/sec 3650.841 nett-ms
+Total 8 cases in 0.04 sec. (0.03 nett-sec.):
+28645.000000 �s/# 8 # 279.281 #/sec 28.645 nett-ms
Average:
-456355.125000 �s/# 1 # 2 #/sec 456.355 nett-ms
+3580.625000 �s/# 1 # 279 #/sec 3.581 nett-ms
Min:
-206160.0 �s/# 1 # 4.851 #/sec 206.160 nett-ms
+2363.00 �s/# 1 # 423.19 #/sec 2.363 nett-ms
Max:
-1035573 �s/# 1 # 0.966 #/sec 1035.573 nett-ms
+5026.00 �s/# 1 # 198.97 #/sec 5.026 nett-ms
********************************************************************************
*** 20000 events ***
% # update / after idle:
% setup {puts [time {after idle {set foo bar}} 20000]}
-0.7776435148043372 microseconds per iteration
+0.2271100787796105 microseconds per iteration
% update; # 20000 idle-events
-1053719 �s/# 1 # 0.949 #/sec 1053.719 nett-ms
+6114.00 �s/# 1 # 163.56 #/sec 6.114 nett-ms
% # update idletasks / after idle:
% setup {puts [time {after idle {set foo bar}} 20000]}
-0.7983015502187538 microseconds per iteration
+0.2063558102809653 microseconds per iteration
% update idletasks; # 20000 idle-events
-1218166 �s/# 1 # 0.821 #/sec 1218.166 nett-ms
+6842.00 �s/# 1 # 146.16 #/sec 6.842 nett-ms
% # update / after 0:
% setup {puts [time {after 0 {set foo bar}} 20000]}
-60.371777274300534 microseconds per iteration
+0.22958006127481248 microseconds per iteration
% update; # 20000 timer-events
-1054948 �s/# 1 # 0.948 #/sec 1054.948 nett-ms
+5023.00 �s/# 1 # 199.08 #/sec 5.023 nett-ms
% # update / after 1:
% setup {puts [time {after 1 {set foo bar}} 20000]; after 1}
-54.87194423870167 microseconds per iteration
+0.42289628864279594 microseconds per iteration
% update; # 20000 timer-events
-1186886 �s/# 1 # 0.843 #/sec 1186.886 nett-ms
+5015.00 �s/# 1 # 199.40 #/sec 5.015 nett-ms
% # cancel forwards "after idle" / 20000 idle-events in queue:
% setup {set i 0; time {set ev([incr i]) [after idle {set foo bar}]} 20000}
-1.2151832710972592 microseconds per iteration
+0.6274397091707883 microseconds per iteration
% set i 0; time {after cancel $ev([incr i])} 20000
-5089423 �s/# 1 # 0.196 #/sec 5089.423 nett-ms
+9334.00 �s/# 1 # 107.14 #/sec 9.334 nett-ms
% cleanup {update}
% # cancel backwards "after idle" / 20000 idle-events in queue:
% setup {set i 0; time {set ev([incr i]) [after idle {set foo bar}]} 20000}
-1.2422568454602523 microseconds per iteration
+0.5642947670694235 microseconds per iteration
% incr i; time {after cancel $ev([incr i -1])} 20000
-2761778 �s/# 1 # 0.362 #/sec 2761.778 nett-ms
+8669.00 �s/# 1 # 115.35 #/sec 8.669 nett-ms
% cleanup {update}
% # cancel forwards "after 0" / 20000 timer-events in queue:
% setup {set i 0; time {set ev([incr i]) [after 0 {set foo bar}]} 20000}
-78.25420995685229 microseconds per iteration
+0.541279021091405 microseconds per iteration
% set i 0; time {after cancel $ev([incr i])} 20000
-4726529 �s/# 1 # 0.212 #/sec 4726.529 nett-ms
+8482.00 �s/# 1 # 117.90 #/sec 8.482 nett-ms
% cleanup {update}
% # cancel backwards "after 0" / 20000 timer-events in queue:
% setup {set i 0; time {set ev([incr i]) [after 0 {set foo bar}]} 20000}
-66.27059267711138 microseconds per iteration
+0.5858990944787551 microseconds per iteration
% incr i; time {after cancel $ev([incr i -1])} 20000
-2551486 �s/# 1 # 0.392 #/sec 2551.486 nett-ms
+8475.00 �s/# 1 # 117.99 #/sec 8.475 nett-ms
% cleanup {update}
% # end 20000 events.
********************************************************************************
-Total 8 cases in 24.93 sec. (19.64 nett-sec.):
-19642935.000000 �s/# 8 # 0.407 #/sec 19642.935 nett-ms
+Total 8 cases in 0.13 sec. (0.06 nett-sec.):
+57954.000000 �s/# 8 # 138.041 #/sec 57.954 nett-ms
Average:
-2455366.875000 �s/# 1 # 0 #/sec 2455.367 nett-ms
+7244.250000 �s/# 1 # 138 #/sec 7.244 nett-ms
Min:
-1053719 �s/# 1 # 0.949 #/sec 1053.719 nett-ms
+5015.00 �s/# 1 # 199.40 #/sec 5.015 nett-ms
Max:
-5089423 �s/# 1 # 0.196 #/sec 5089.423 nett-ms
+9334.00 �s/# 1 # 107.14 #/sec 9.334 nett-ms
********************************************************************************
*** 40000 events ***
% # update / after idle:
% setup {puts [time {after idle {set foo bar}} 40000]}
-0.8032495346328434 microseconds per iteration
+0.25244343820280224 microseconds per iteration
% update; # 40000 idle-events
-6374377 �s/# 1 # 0.157 #/sec 6374.377 nett-ms
+12555.0 �s/# 1 # 79.650 #/sec 12.555 nett-ms
% # update idletasks / after idle:
% setup {puts [time {after idle {set foo bar}} 40000]}
-0.803433981377615 microseconds per iteration
+0.22283572595512138 microseconds per iteration
% update idletasks; # 40000 idle-events
-6220205 �s/# 1 # 0.161 #/sec 6220.205 nett-ms
+12614.0 �s/# 1 # 79.277 #/sec 12.614 nett-ms
% # update / after 0:
% setup {puts [time {after 0 {set foo bar}} 40000]}
-159.24259430280893 microseconds per iteration
+0.22941967280109807 microseconds per iteration
% update; # 40000 timer-events
-6376218 �s/# 1 # 0.157 #/sec 6376.218 nett-ms
+10821.0 �s/# 1 # 92.413 #/sec 10.821 nett-ms
% # update / after 1:
% setup {puts [time {after 1 {set foo bar}} 40000]; after 1}
-159.7197099149909 microseconds per iteration
+0.4345966278002625 microseconds per iteration
% update; # 40000 timer-events
-6226214 �s/# 1 # 0.161 #/sec 6226.214 nett-ms
+10186.0 �s/# 1 # 98.174 #/sec 10.186 nett-ms
% # cancel forwards "after idle" / 40000 idle-events in queue:
% setup {set i 0; time {set ev([incr i]) [after idle {set foo bar}]} 40000}
-1.2706055081892749 microseconds per iteration
+0.6570634602658406 microseconds per iteration
% set i 0; time {after cancel $ev([incr i])} 40000
-26786735 �s/# 1 # 0.037 #/sec 26786.735 nett-ms
+17576.0 �s/# 1 # 56.896 #/sec 17.576 nett-ms
% cleanup {update}
% # cancel backwards "after idle" / 40000 idle-events in queue:
% setup {set i 0; time {set ev([incr i]) [after idle {set foo bar}]} 40000}
-1.3183932539324847 microseconds per iteration
+0.5936298189117898 microseconds per iteration
% incr i; time {after cancel $ev([incr i -1])} 40000
-17572791 �s/# 1 # 0.057 #/sec 17572.791 nett-ms
+18263.0 �s/# 1 # 54.756 #/sec 18.263 nett-ms
% cleanup {update}
% # cancel forwards "after 0" / 40000 timer-events in queue:
% setup {set i 0; time {set ev([incr i]) [after 0 {set foo bar}]} 40000}
-167.1848310355546 microseconds per iteration
+0.6825812664338039 microseconds per iteration
% set i 0; time {after cancel $ev([incr i])} 40000
-23609600 �s/# 1 # 0.042 #/sec 23609.600 nett-ms
+18437.0 �s/# 1 # 54.239 #/sec 18.437 nett-ms
% cleanup {update}
% # cancel backwards "after 0" / 40000 timer-events in queue:
% setup {set i 0; time {set ev([incr i]) [after 0 {set foo bar}]} 40000}
-187.4246615241845 microseconds per iteration
+0.6071826449406578 microseconds per iteration
% incr i; time {after cancel $ev([incr i -1])} 40000
-15856877 �s/# 1 # 0.063 #/sec 15856.877 nett-ms
+18167.0 �s/# 1 # 55.045 #/sec 18.167 nett-ms
% cleanup {update}
% # end 40000 events.
********************************************************************************
-Total 8 cases in 136.16 sec. (109.02 nett-sec.):
-109023017.000000 �s/# 8 # 0.073 #/sec 109023.017 nett-ms
+Total 8 cases in 0.27 sec. (0.12 nett-sec.):
+118619.000000 �s/# 8 # 67.443 #/sec 118.619 nett-ms
Average:
-13627877.125000 �s/# 1 # 0 #/sec 13627.877 nett-ms
+14827.375000 �s/# 1 # 67 #/sec 14.827 nett-ms
Min:
-6220205 �s/# 1 # 0.161 #/sec 6220.205 nett-ms
+10186.0 �s/# 1 # 98.174 #/sec 10.186 nett-ms
Max:
-26786735 �s/# 1 # 0.037 #/sec 26786.735 nett-ms
+18437.0 �s/# 1 # 54.239 #/sec 18.437 nett-ms
********************************************************************************
*** 60000 events ***
% # update / after idle:
% setup {puts [time {after idle {set foo bar}} 60000]}
-0.8182699151961983 microseconds per iteration
+0.24563494749362536 microseconds per iteration
% update; # 60000 idle-events
-15858878 �s/# 1 # 0.063 #/sec 15858.878 nett-ms
+18051.0 �s/# 1 # 55.399 #/sec 18.051 nett-ms
% # update idletasks / after idle:
% setup {puts [time {after idle {set foo bar}} 60000]}
-0.8803295619587623 microseconds per iteration
+0.21445008192108608 microseconds per iteration
% update idletasks; # 60000 idle-events
-17956326 �s/# 1 # 0.056 #/sec 17956.326 nett-ms
+18072.0 �s/# 1 # 55.334 #/sec 18.072 nett-ms
% # update / after 0:
% setup {puts [time {after 0 {set foo bar}} 60000]}
-322.06103893451586 microseconds per iteration
+0.23241359097710046 microseconds per iteration
% update; # 60000 timer-events
-16163331 �s/# 1 # 0.062 #/sec 16163.331 nett-ms
+14384.0 �s/# 1 # 69.522 #/sec 14.384 nett-ms
% # update / after 1:
% setup {puts [time {after 1 {set foo bar}} 60000]; after 1}
-289.082394018237 microseconds per iteration
+0.35161965092411024 microseconds per iteration
% update; # 60000 timer-events
-18014810 �s/# 1 # 0.056 #/sec 18014.810 nett-ms
+14609.0 �s/# 1 # 68.451 #/sec 14.609 nett-ms
% # cancel forwards "after idle" / 60000 idle-events in queue:
% setup {set i 0; time {set ev([incr i]) [after idle {set foo bar}]} 60000}
-1.3695946010245827 microseconds per iteration
+0.6432058961369153 microseconds per iteration
% set i 0; time {after cancel $ev([incr i])} 60000
-93546474 �s/# 1 # 0.011 #/sec 93546.474 nett-ms
+26497.0 �s/# 1 # 37.740 #/sec 26.497 nett-ms
% cleanup {update}
% # cancel backwards "after idle" / 60000 idle-events in queue:
% setup {set i 0; time {set ev([incr i]) [after idle {set foo bar}]} 60000}
-1.307978695705962 microseconds per iteration
+0.562605341812965 microseconds per iteration
% incr i; time {after cancel $ev([incr i -1])} 60000
-60641297 �s/# 1 # 0.016 #/sec 60641.297 nett-ms
+27942.0 �s/# 1 # 35.788 #/sec 27.942 nett-ms
% cleanup {update}
% # cancel forwards "after 0" / 60000 timer-events in queue:
% setup {set i 0; time {set ev([incr i]) [after 0 {set foo bar}]} 60000}
-308.5513306736647 microseconds per iteration
+0.5777139360368627 microseconds per iteration
% set i 0; time {after cancel $ev([incr i])} 60000
-67615113 �s/# 1 # 0.015 #/sec 67615.113 nett-ms
+26612.0 �s/# 1 # 37.577 #/sec 26.612 nett-ms
% cleanup {update}
% # cancel backwards "after 0" / 60000 timer-events in queue:
% setup {set i 0; time {set ev([incr i]) [after 0 {set foo bar}]} 60000}
-387.5346666320227 microseconds per iteration
+0.5716886757076579 microseconds per iteration
% incr i; time {after cancel $ev([incr i -1])} 60000
-56802845 �s/# 1 # 0.018 #/sec 56802.845 nett-ms
+27435.0 �s/# 1 # 36.450 #/sec 27.435 nett-ms
% cleanup {update}
% # end 60000 events.
********************************************************************************
-Total 8 cases in 425.33 sec. (346.60 nett-sec.):
-346599074.000000 �s/# 8 # 0.023 #/sec 346599.074 nett-ms
+Total 8 cases in 0.38 sec. (0.17 nett-sec.):
+173602.000000 �s/# 8 # 46.082 #/sec 173.602 nett-ms
Average:
-43324884.250000 �s/# 1 # 0 #/sec 43324.884 nett-ms
+21700.250000 �s/# 1 # 46 #/sec 21.700 nett-ms
Min:
-15858878 �s/# 1 # 0.063 #/sec 15858.878 nett-ms
+14384.0 �s/# 1 # 69.522 #/sec 14.384 nett-ms
Max:
-93546474 �s/# 1 # 0.011 #/sec 93546.474 nett-ms
+27942.0 �s/# 1 # 35.788 #/sec 27.942 nett-ms
********************************************************************************
