pedeathtrian 99 Posted March 2, 2016 I will start with putting function code because it's quite small, and for reference (starting description comment omitted). /// --- validate general input #include "..\paramsCheck.inc" paramsCheck(_this,isEqualType,[]) private _cnt = count _this; for "_i" from 1 to _cnt do { _this pushBack (_this deleteAt floor random _cnt); }; _this According to BIS_fnc_arrayShuffle: Description: This returns a new array with randomized order of elements from input array Now, what's wrong. As you can see, no new array is created, and instead passed array is shuffled in-place. Function itself fails to shuffle (at least for what I think shuffle is). What I think shuffle is: all elements of input array get fairly equal chances to appear in any position in output array. What we have in function? TL;DR. First elements are less likely to be shuffled than last ones. Let's say we have array of N elements numbered 0, 1, ... N-1. Fair probability for any element to take any position is 1/N. Line 24 removes element with random index M (all consequent elements moved one element towards the array front) and pushes it to array's back. Operation affects positions of elements in range [M, ... N-1] unless M == N-1 (in which case nothing is changed, but delete and insertion performed!). Position of M elements (numbered 0..M-1) is unchanged. For arbitrary M in [0, 1, ..., N-1] you have the probability (N-M-1)/N that first M elements will remain on their positions after this iteration. Entire loop lasts N iterations. So the probability of element not being picked up and not moved in entire loop is ((N-M-1)/N)N. Full probability of element to stay on its initial place also includes the cases when element goes to back and after some iterations shifts to its initial place. For 0th element probability of shifting back to 0th position is 1/N * (N-1)/N * (N-2)/N * ... * 1/N = (N-1)!/(NN). For the last exactly 1/N (simply probability of picking specific element; fair for this position, still not fair for others) -- if last element moved to array's back in last iteration. Assuming that , probability of 0th element staying in 0th position first falls and has minimum in N=5, then grows and asymptotically strives for 1/e, i.e. ~0.367879441, no matter what size array is. When in fact it should be exactly 1/N for any N. That is, having array of 10 elements, for first element (M=0) you will have probability (10-0-1)/10 = 0.9 (90%) that it stays on its place after first iteration. Probability 0.8 (80%) of that two first elements are not shuffled after first iteration (quite obvious). Probability of first element staying in first position after entire loop is 0.348714728 (~34.8%) when it should be 10%. Sorry, did not do the maths for other elements, but I think it's enough already to state that shuffle fails. The easiest way to fix the loop is to rewrite it like this: for "_i" from 1 to _cnt do { _this pushBack (_this deleteAt floor random (_cnt+1-_i)); }; Thus not picking any element second time and providing fair 1/N probability for all elements. However, I don't like this approach because of too many (unnecessary) deletes, causing multiple elements to shift towards array front, meaning worst case complexity of O(n2) (if random always returns 0). I don't know how arrays work inside. If shifting elements of arbitrary types is quite costly operation (very likely for vector-like containers filled with data structures itself, not pointers), it's better shift numbers (indexes of elements). Here's my implementation of function, fixing both issues: /// --- validate general input #include "..\paramsCheck.inc" paramsCheck(_this,isEqualType,[]) private ["_cnt", "_result"]; _cnt = count _this; _result = []; if (_cnt > 0) then { private ["_i", "_idxs"]; _idxs = []; _idxs resize _cnt; for [{_i = 0}, {_i < _cnt}, {_i = _i + 1}] do { _idxs set [_i, _i]; }; _result resize _cnt; for [{_i = 0}, {_i < (_cnt-1)}, {_i = _i + 1}] do { _result set [_i, _this select (_idxs deleteAt floor random (_cnt-_i))]; }; _result set [_cnt-1, _this select (_idxs select 0)]; }; _result It does multiple deletes from array too, but at least elements are always numbers. Whoever wants a fair shuffle, feel free to use. Having BIS_fnc_sortBy function discovered broken recently, I think there should be some review in arrays functions code. And I'll be digging too, hehe :icon_twisted: I see what you did there, KK There's hotfix coming soon, I wonder if BIS could fix this function too. Best regards. 1 Share this post Link to post Share on other sites
Nikander 123 Posted March 2, 2016 So glad it was not just me, because I noticed my mission doesn't randomize very well anymore using BIS_fnc_arrayShuffle. The list of broken features since 1.56 update is getting longer day-by-day. Nikander Share this post Link to post Share on other sites
_.Dardo._ 15 Posted March 2, 2016 Cba_fnc_shuffle works a way better,i didnt even know about this bis func. Inviato dal mio LG-D855 utilizzando Tapatalk Share this post Link to post Share on other sites
pedeathtrian 99 Posted March 3, 2016 Cba_fnc_shuffle works a way better,i didnt even know about this bis func. Checked their code. Still (probably) inefficient. Although they don't have two BIS_fnc_arrayShuffle's issues I mentioned in theme start post, they have some flaws: Creating a full copy of input array which is (probably) not actually necessary, causing huge memory overhead for complex element types and big elements counts. Using deleteAt on this copy which can lead to up to N*(N-1)/2 single element shifts (in worst case). Building up an output array from empty to full using pushBack, possibly causing multiple reallocations, whereas final elements count is known from the beginning. Again, I don't know how BIS array's guts work. Whether they have reallocations (shrinking block) after multiple deleteAt's (if so, one more disadvantage for CBA's way; if not, they have memory overhead, so no win there anyway). Or how operations-consuming deleteAt and pushBack are. Whether shifting element depends on element type complexity or not... Unless they use something special under the hood, abovementioned list negatively affects CBA's shuffle as well. OK, let's guess. Element type can be anything, so most likely some smart pointer to some variant class, and actual data stored somewhere else in heap. And array is some kind of vector. That way first flaw from my list diminishes since all elements from the copy go to output array without any reallocations or movements of actual data. Array reallocations will apply to smart pointer class type, so quite cheap (but still present). If only some BIS employees could give us some precious insider information on how to work extremely effectively with their arrays... :) 1 Share this post Link to post Share on other sites
_.Dardo._ 15 Posted March 3, 2016 Checked their code. Still (probably) inefficient. Although they don't have two BIS_fnc_arrayShuffle's issues I mentioned in theme start post, they have some flaws: Creating a full copy of input array which is (probably) not actually necessary, causing huge memory overhead for complex element types and big elements counts. Using deleteAt on this copy which can lead to up to N*(N-1)/2 single element shifts (in worst case). Building up an output array from empty to full using pushBack, possibly causing multiple reallocations, whereas final elements count is known from the beginning. Again, I don't know how BIS array's guts work. Whether they have reallocations (shrinking block) after multiple deleteAt's (if so, one more disadvantage for CBA's way; if not, they have memory overhead, so no win there anyway). Or how operations-consuming deleteAt and pushBack are. Whether shifting element depends on element type complexity or not... Unless they use something special under the hood, abovementioned list negatively affects CBA's shuffle as well.OK, let's guess. Element type can be anything, so most likely some smart pointer to some variant class, and actual data stored somewhere else in heap. And array is some kind of vector. That way first flaw from my list diminishes since all elements from the copy go to output array without any reallocations or movements of actual data. Array reallocations will apply to smart pointer class type, so quite cheap (but still present). If only some BIS employees could give us some precious insider information on how to work extremely effectively with their arrays... :) Well,it means ill stick with your code.So right now there is no technical information/data about arrays? Share this post Link to post Share on other sites
pedeathtrian 99 Posted March 3, 2016 Well,it means ill stick with your code. If you can test it against CBA and post the results here it will be great. I can't reach windows machine atm. So right now there is no technical information/data about arrays? Nope, I only have some basic info from biki and this forum. 1 Share this post Link to post Share on other sites
Greenfist 1863 Posted March 3, 2016 If performance is a concern, you should replace sets with pushbacks and for loops with for "_i" from 0 to (cnt-1) And the resize is redundant, since set can add to array on its own. Also, you can measure the execution time in the debug console to compare different functions. 1 Share this post Link to post Share on other sites
pedeathtrian 99 Posted March 3, 2016 If performance is a concern, you should replace sets with pushbacks and for loops with for "_i" from 0 to (cnt-1) And the resize is redundant, since set can add to array on its own. Also, you can measure the execution time in the debug console to compare different functions. Thanks for the tip on loops. Looks reasonable: for with three Code blocks which could be any code should generally be slower then hardcoded iterated form. On others I kinda disagree. I need resize to make sure there's only one reallocation for all elements of array. Since I fill array consequently I can't rely on resize done by sets for the same reason: there can be multiple reallocations. For the same reason I cannot use pushBacks. They simply cannot work faster than one resize + multiple sets. Now writing script to measure performance of scripts for different types of elements in arrays, for different sizes, etc. UPD. I'm going to set up empty mission in VR and disable simulation for player. What else can I do to minimize side effects? Share this post Link to post Share on other sites
Greenfist 1863 Posted March 3, 2016 Ok, I was just thinking how the wiki claims that set it much slower than pushback. Share this post Link to post Share on other sites
pedeathtrian 99 Posted March 4, 2016 This post contains misinformation. See next post for details. Hello, here I am again, now with some numbers. I wrote some testing code to compare performance of different implementations of shuffle function. So this is the report. 1. Testing environment CPU: Intel® Core i7-3770K CPU @ 3.40GHz RAM: 16 GiB DDR3 1600MHz OS: Windows 7 x64 Ultimate ArmA3: current stable version, main branch, 1.56.134787 Loaded mods: CBA_A3 current version from Steam workshop, 2.3.1.160220 Start parameters: -showScriptErrors -maxMem=2047 -cpuCount=8 -noPause 2. Testing code I created empty mission in VR; put trigger there and a rifleman in its area. After few seconds testing procedure starts working. mission.sqm: version=12; class Mission { addOns[]= { "A3_Characters_F_OPFOR", "a3_characters_f", "map_vr" }; addOnsAuto[]= { "A3_Characters_F_OPFOR", "a3_characters_f", "map_vr" }; randomSeed=5632393; class Intel { timeOfChanges=1800.0002; startWeather=0; startWind=0.1; startWaves=0.1; forecastWeather=0; forecastWind=0.1; forecastWaves=0.1; forecastLightnings=0.1; year=2035; day=28; hour=13; minute=37; startFogDecay=0.0049999999; forecastFogDecay=0.0049999999; }; class Groups { items=1; class Item0 { side="EAST"; class Vehicles { items=1; class Item0 { position[]={1.3241079,5,0.91894531}; id=0; side="EAST"; vehicle="O_Soldier_F"; player="PLAYER COMMANDER"; leader=1; skill=0.60000002; init="this setPos [0,0,0]"; }; }; }; }; class Sensors { items=1; class Item0 { position[]={-2.7722609,5,2.7626953}; activationBy="ANY"; timeoutMin=3; timeoutMid=3; timeoutMax=3; interruptable=1; age="UNKNOWN"; expActiv="call compile preprocessFileLineNumbers ""test_shuffle.sqf"""; class Effects { sound="FD_Timer_F"; }; }; }; }; class Intro { addOns[]= { "map_vr" }; addOnsAuto[]= { "map_vr" }; randomSeed=14954384; class Intel { timeOfChanges=1800.0002; startWeather=0; startWind=0.1; startWaves=0.1; forecastWeather=0; forecastWind=0.1; forecastWaves=0.1; forecastLightnings=0.1; year=2035; day=28; hour=13; minute=37; startFogDecay=0.0049999999; forecastFogDecay=0.0049999999; }; }; class OutroWin { addOns[]= { "map_vr" }; addOnsAuto[]= { "map_vr" }; randomSeed=5667227; class Intel { timeOfChanges=1800.0002; startWeather=0; startWind=0.1; startWaves=0.1; forecastWeather=0; forecastWind=0.1; forecastWaves=0.1; forecastLightnings=0.1; year=2035; day=28; hour=13; minute=37; startFogDecay=0.0049999999; forecastFogDecay=0.0049999999; }; }; class OutroLoose { addOns[]= { "map_vr" }; addOnsAuto[]= { "map_vr" }; randomSeed=424579; class Intel { timeOfChanges=1800.0002; startWeather=0; startWind=0.1; startWaves=0.1; forecastWeather=0; forecastWind=0.1; forecastWaves=0.1; forecastLightnings=0.1; year=2035; day=28; hour=13; minute=37; startFogDecay=0.0049999999; forecastFogDecay=0.0049999999; }; }; Testing code, "test_shuffle.sqf". Mostly functions to populate input arrays. #define DEF_MAX_DEPTH 5 #define DEF_MAX_ELEMS 5 #define DEF_MIN_STRLEN 7 #define DEF_MAX_STRLEN 63 #define DEF_SHUFFLE_RUNS 1000000 { _x enableSimulation false; } forEach (entities "All"); pdth_fnc_shuf = compile preprocessFileLineNumbers "pdth_fnc_shuffle.sqf"; cba_fnc_shuf = CBA_fnc_shuffle; bis_fnc_shuf = compile preprocessFileLineNumbers "bis_fnc_shuffle.sqf"; bis_fnc_shuf_v = BIS_fnc_shuffleArray; fnc_generate_bool = { 0.5 > (random(1)); }; fnc_generate_scalar = { random (1e5) - 2e5; }; fnc_generate_string = { private ["_arr", "_i", "_count"]; _count = DEF_MIN_STRLEN + 1 + floor random(DEF_MAX_STRLEN-DEF_MIN_STRLEN); _arr = []; for "_i" from 1 to _count do { _arr pushBack (32 + floor random 95); // ascii, without 127 }; toString _arr; }; fnc_generate_code = { compile (["if (true) then {2+2} else {5}", "{ _x = _x + 1 } forEach [1,2,3]", "a = 42"] call BIS_fnc_selectRandom); }; fnc_generate_object = { (entities "All") call BIS_fnc_selectRandom; }; fnc_generate_side = { [west, east, resistance] call BIS_fnc_selectRandom }; generatedTypes = ["ARRAY", "BOOL", "CODE", "OBJECT", "SCALAR", "SIDE", "STRING", "NIL"]; fnc_generate_type = { private "_type"; _type = [_this, 2, generatedTypes call BIS_fnc_selectRandom, [""]] call BIS_fnc_param; switch _type do { case "ARRAY": { private ["_maxDepth", "_maxElems"]; _maxDepth = [_this, 0, DEF_MAX_DEPTH, [0]] call BIS_fnc_param; _maxElems = [_this, 1, DEF_MAX_ELEMS, [0]] call BIS_fnc_param; if (_maxDepth < 1) then { _maxDepth = DEF_MAX_DEPTH; }; if (_maxElems < 1) then { _maxElems = DEF_MAX_ELEMS; }; [_maxDepth, _maxElems] call fnc_generate_array; }; case "BOOL": { call fnc_generate_bool; }; case "CODE": { call fnc_generate_code; }; case "OBJECT": { call fnc_generate_object; }; case "SCALAR": { call fnc_generate_scalar; }; case "SIDE": { call fnc_generate_side; }; case "STRING": { call fnc_generate_string; }; default {nil}; }; }; fnc_generate_array = { private ["_maxDepth", "_maxElems", "_ret", "_i", "_cnt", "_types"]; _maxDepth = [_this, 0, DEF_MAX_DEPTH, [0]] call BIS_fnc_param; _maxElems = [_this, 1, DEF_MAX_ELEMS, [0]] call BIS_fnc_param; _types = [_this, 2, generatedTypes, [[]]] call BIS_fnc_param; _ret = []; if (_maxDepth < 1) then { _maxDepth = DEF_MAX_DEPTH; }; if (_maxElems < 1) then { _maxElems = DEF_MAX_ELEMS; }; _cnt = floor random (1+_maxElems); for "_i" from 1 to _cnt do { _ret pushBack ([_maxDepth-1, _maxElems, _types call BIS_fnc_selectRandom] call fnc_generate_type); }; _ret }; firstElem = "FirstElem"; fnc_generate_array_for_shuffle = { private ["_i", "_cnt", "_types", "_push"]; _cnt = [_this, 0, DEF_MAX_ELEMS, [0]] call BIS_fnc_param; _types = [_this, 1, generatedTypes, [[]]] call BIS_fnc_param; _ret = []; if (_cnt < 1) then { _cnt = DEF_MAX_ELEMS; }; if ("STRING" in _types) then { _ret pushBack firstElem; } else { _push = [DEF_MAX_DEPTH, DEF_MAX_ELEMS, _types call BIS_fnc_selectRandom] call fnc_generate_type; if (isNil "_push") then { _ret set [0, nil]; } else { _ret pushBack _push; }; }; for "_i" from 1 to (_cnt-1) do { _push = [DEF_MAX_DEPTH, DEF_MAX_ELEMS, _types call BIS_fnc_selectRandom] call fnc_generate_type; if (isNil "_push") then { _ret set [_i, nil]; } else { _ret pushBack _push; }; }; _ret }; private ["_arrForShuffle", /*"_arrShuffled",*/ "_numEls", "_k", "_func", "_st", "_en", "_step", "_times", "_sum", "_runs", "_avg", "_typs", "_usedTypes", "_csh", "_rep"]; _usedTypes = []; { _usedTypes pushBack [_x]; // for each type separately } forEach generatedTypes; _usedTypes pushBack generatedTypes; // and for mixed arrays { _numEls = _x; diag_log format ["Running tests for arrays of size %1", _numEls]; { _typs = _x; _arrForShuffle = [_numEls, _typs] call fnc_generate_array_for_shuffle; _times = []; _sum = 0; diag_log format [" Element types: %1", _typs]; { _func = _x; _runs = ceil (DEF_SHUFFLE_RUNS / _numEls); _st = diag_tickTime; for "_k" from 1 to _runs do { private "_arrShuffled"; // making sure memory freed (?) after every shuffle, otherwise consequent calls can fail _arrShuffled = _arrForShuffle call _func; _csh = count _arrShuffled; }; _en = diag_tickTime; _step = _en - _st; _avg = _step / _runs; _times pushBack _step; _sum = _sum + _step; if (isNil "_csh" && _forEachIndex == 3) then { _csh = count _arrForShuffle; // bis_fnc_shuf_v shuffles in-place }; if (isNil "_csh") then { diag_log format [" %1 shuffles run; avg. time per one shuffle: %2", _runs, _avg]; } else { diag_log format [" (last output %1) %2 shuffles run; avg. time per one shuffle: %3", _csh, _runs, _avg]; }; } forEach [pdth_fnc_shuf, cba_fnc_shuf, bis_fnc_shuf, bis_fnc_shuf_v]; _arrForShuffle = nil; // release array, so memory will be collected (?) { _times set [_forEachIndex, 100*_x / _sum]; } forEach _times; diag_log format [" Time passed during each call, %1: %2", "%", _times]; } forEach _usedTypes; } forEach [3, 10, 30, 100, 301, 1000, 3010, 10000, 30103/*, 100000, 301030, 1000000, 3010300, 9999999*/]; { _x enableSimulation true; } forEach (entities "All"); endMission "END1"; Tested functions defined in lines pdth_fnc_shuf = compile preprocessFileLineNumbers "pdth_fnc_shuffle.sqf"; cba_fnc_shuf = CBA_fnc_shuffle; bis_fnc_shuf = compile preprocessFileLineNumbers "bis_fnc_shuffle.sqf"; bis_fnc_shuf_v = BIS_fnc_shuffleArray; Testing output is produced in the same order. pdth_fnc_shuf is the function I wrote for this task, slightly changed since the first post, thx to Greenfist for useful tip on for loop; defined in "pdth_fnc_shuffle.sqf": /// --- validate general input #include "\A3\functions_f\paramsCheck.inc" paramsCheck(_this,isEqualType,[]) private ["_cnt", "_result"]; _cnt = count _this; _result = []; if (_cnt > 0) then { private ["_i", "_idxs"]; _idxs = []; _idxs resize _cnt; for "_i" from 0 to (cnt-1) do { _idxs set [_i, _i]; }; _result resize _cnt; for "_i" from 0 to (cnt-2) do { _result set [_i, _this select (_idxs deleteAt floor random (_cnt-_i))]; }; _result set [_cnt-1, _this select (_idxs select 0)]; }; _result cba_fnc_shuf is unchanged function from CBA. bis_fnc_shuf is function based on BIS's BIS_fnc_shuffleArray with slight changes done by me to conform function specifications: produce new array, leave input array intact, fair shuffling (see first post). /// --- validate general input #include "\A3\functions_f\paramsCheck.inc" paramsCheck(_this,isEqualType,[]) private ["_cnt", "_res"]; _cnt = count _this; _res = +_this; for "_i" from 1 to (_cnt-1) do { _res pushBack (_res deleteAt floor random (_cnt+1-_i)); }; _res pushBack (_res deleteAt 0); // omit extra call to random selecting from single element. _res bis_fnc_shuf_v is unchanged version of BIS_fnc_shuffleArray. Works incorrectly therefore should be considered off competition. Only here for reference. Produces incorrect output (no fair shuffling), shuffles input array in-place (therefore shows good times). 3. Test run All functions are given exactly the same input, generated randomly by functions in "test_shuffle.sqf". Vanilla BIS_fnc_shuffleArray shuffles in-place, therefore called last. Time measuring done using diag_tickTime scripting command. Since function call can be fully performed (especially for small arrays) in very short period of time, therefore not being able to be measured accurately, all functions called in loops of equal amount of repetitions so produce enough delay to be measured. Times measured in seconds. Array counts used in test: [3, 10, 30, 100, 301, 1000, 3010, 10000, 30103, 100000]. At lest DEF_SHUFFLE_RUNS array elements are shuffled by each function for each array count. Average time calculated for single shuffle run is logged in report. Types used for populating array: ["ARRAY", "BOOL", "CODE", "OBJECT", "SCALAR", "SIDE", "STRING", "NIL"]. For each of given type, array populated fully with only this type. After all types tested, test run for array populated with mix of mentioned types. For "ARRAY" type, tested array is populated with arrays, in turn containing mixed types as their child types (should not affect the root). "ARRAY"s contain other "ARRAY"s too. Maximum tree depth is limited by DEF_MAX_DEPTH macro. 4. Report output: 17:15:44 "Running tests for arrays of size 3" 17:15:44 " Element types: ["ARRAY"]" 17:15:51 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.0811e-005" 17:16:10 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 5.74739e-005" 17:16:17 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.1042e-005" 17:16:18 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 3.44098e-006" 17:16:18 " Time passed during each call, %: [20.2505,55.926,20.4752,3.34831]" 17:16:18 " Element types: ["BOOL"]" 17:16:25 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.0751e-005" 17:16:41 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 4.70669e-005" 17:16:47 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 1.9707e-005" 17:16:49 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 3.447e-006" 17:16:49 " Time passed during each call, %: [22.8103,51.7379,21.6627,3.78908]" 17:16:49 " Element types: ["CODE"]" 17:16:56 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.1012e-005" 17:17:12 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 4.82039e-005" 17:17:18 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.0142e-005" 17:17:19 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 3.45002e-006" 17:17:19 " Time passed during each call, %: [22.6403,51.9395,21.7029,3.71738]" 17:17:19 " Element types: ["OBJECT"]" 17:17:26 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.0928e-005" 17:17:43 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 5.10539e-005" 17:17:50 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 1.98539e-005" 17:17:51 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 3.45899e-006" 17:17:51 " Time passed during each call, %: [21.9613,53.5747,20.8342,3.62978]" 17:17:51 " Element types: ["SCALAR"]" 17:17:58 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.0883e-005" 17:18:15 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 5.07209e-005" 17:18:22 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 1.9377e-005" 17:18:23 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 3.453e-006" 17:18:23 " Time passed during each call, %: [22.1138,53.7105,20.5191,3.65652]" 17:18:23 " Element types: ["SIDE"]" 17:18:30 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.0991e-005" 17:18:45 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 4.72109e-005" 17:18:52 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 1.9719e-005" 17:18:53 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 3.453e-006" 17:18:53 " Time passed during each call, %: [22.9726,51.6679,21.5805,3.77898]" 17:18:53 " Element types: ["STRING"]" 17:19:00 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.0991e-005" 17:19:16 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 4.88279e-005" 17:19:23 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 1.9866e-005" 17:19:24 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 3.46792e-006" 17:19:24 " Time passed during each call, %: [22.5339,52.417,21.3262,3.72283]" 17:19:24 " Element types: ["NIL"]" 17:19:31 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.0919e-005" 17:19:47 " (last output 0) 333334 shuffles run; avg. time per one shuffle: 4.74269e-005" 17:19:54 " (last output 0) 333334 shuffles run; avg. time per one shuffle: 1.959e-005" 17:19:55 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 3.453e-006" 17:19:55 " Time passed during each call, %: [22.8901,51.8957,21.4358,3.77836]" 17:19:55 " Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]" 17:20:02 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 2.094e-005" 17:20:18 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 4.87289e-005" 17:20:25 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 1.9791e-005" 17:20:26 " (last output 3) 333334 shuffles run; avg. time per one shuffle: 3.453e-006" 17:20:26 " Time passed during each call, %: [22.5372,52.4458,21.3006,3.71638]" 17:20:26 "Running tests for arrays of size 10" 17:20:26 " Element types: ["ARRAY"]" 17:20:28 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 2.11099e-005" 17:20:38 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 9.806e-005" 17:20:42 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 4.71701e-005" 17:20:43 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 3.45001e-006" 17:20:43 " Time passed during each call, %: [12.433,57.7537,27.7814,2.03193]" 17:20:43 " Element types: ["BOOL"]" 17:20:45 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 2.08499e-005" 17:20:52 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 7.07599e-005" 17:20:56 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 4.30801e-005" 17:20:56 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 3.44025e-006" 17:20:56 " Time passed during each call, %: [15.0944,51.227,31.1881,2.49058]" 17:20:56 " Element types: ["CODE"]" 17:20:59 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 2.112e-005" 17:21:06 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 7.64102e-005" 17:21:11 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 4.48499e-005" 17:21:11 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 3.46008e-006" 17:21:11 " Time passed during each call, %: [14.4816,52.3931,30.7527,2.37252]" 17:21:11 " Element types: ["OBJECT"]" 17:21:13 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 2.11099e-005" 17:21:21 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 8.05499e-005" 17:21:26 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 4.36401e-005" 17:21:26 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 3.45978e-006" 17:21:26 " Time passed during each call, %: [14.1906,54.1477,29.336,2.32575]" 17:21:26 " Element types: ["SCALAR"]" 17:21:28 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 2.11002e-005" 17:21:36 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 8.10498e-005" 17:21:40 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 4.25e-005" 17:21:41 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 3.43994e-006" 17:21:41 " Time passed during each call, %: [14.2482,54.7301,28.6988,2.32287]" 17:21:41 " Element types: ["SIDE"]" 17:21:43 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 2.10501e-005" 17:21:50 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 7.05399e-005" 17:21:54 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 4.31e-005" 17:21:55 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 3.42011e-006" 17:21:55 " Time passed during each call, %: [15.2415,51.0751,31.207,2.47636]" 17:21:55 " Element types: ["STRING"]" 17:21:57 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 2.10999e-005" 17:22:05 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 7.89301e-005" 17:22:09 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 4.345e-005" 17:22:09 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 3.46985e-006" 17:22:09 " Time passed during each call, %: [14.3585,53.7123,29.5679,2.36125]" 17:22:09 " Element types: ["NIL"]" 17:22:11 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 2.099e-005" 17:22:18 " (last output 0) 100000 shuffles run; avg. time per one shuffle: 7.07202e-005" 17:22:23 " (last output 0) 100000 shuffles run; avg. time per one shuffle: 4.29199e-005" 17:22:23 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 3.43994e-006" 17:22:23 " Time passed during each call, %: [15.2024,51.2205,31.0856,2.49145]" 17:22:23 " Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]" 17:22:25 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 2.10098e-005" 17:22:33 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 8.03201e-005" 17:22:38 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 4.37e-005" 17:22:38 " (last output 10) 100000 shuffles run; avg. time per one shuffle: 3.42011e-006" 17:22:38 " Time passed during each call, %: [14.1528,54.1058,29.4375,2.30388]" 17:22:38 "Running tests for arrays of size 30" 17:22:38 " Element types: ["ARRAY"]" 17:22:39 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 2.11794e-005" 17:22:47 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000258745" 17:22:51 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000122938" 17:22:51 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 3.41943e-006" 17:22:51 " Time passed during each call, %: [5.21298,63.686,30.2593,0.841639]" 17:22:52 " Element types: ["BOOL"]" 17:22:52 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 2.1119e-005" 17:22:57 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000140547" 17:23:01 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000110279" 17:23:01 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 3.44964e-006" 17:23:01 " Time passed during each call, %: [7.66863,51.0349,40.0439,1.25262]" 17:23:01 " Element types: ["CODE"]" 17:23:01 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 2.14797e-005" 17:23:07 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000167967" 17:23:11 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000115198" 17:23:11 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 3.42034e-006" 17:23:11 " Time passed during each call, %: [6.97247,54.5232,37.394,1.11027]" 17:23:11 " Element types: ["OBJECT"]" 17:23:12 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 2.11199e-005" 17:23:18 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000175227" 17:23:21 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000110698" 17:23:21 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 3.42034e-006" 17:23:21 " Time passed during each call, %: [6.80267,56.4401,35.6555,1.10168]" 17:23:21 " Element types: ["SCALAR"]" 17:23:22 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 2.10897e-005" 17:23:28 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000168897" 17:23:31 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000108297" 17:23:31 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 3.42034e-006" 17:23:31 " Time passed during each call, %: [6.99018,55.9809,35.8952,1.13367]" 17:23:31 " Element types: ["SIDE"]" 17:23:32 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 2.10311e-005" 17:23:37 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000138416" 17:23:40 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000110698" 17:23:40 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 3.42034e-006" 17:23:40 " Time passed during each call, %: [7.68778,50.597,40.4649,1.25028]" 17:23:40 " Element types: ["STRING"]" 17:23:41 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 2.11794e-005" 17:23:47 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000181976" 17:23:51 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 0.000111088" 17:23:51 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 3.42034e-006" 17:23:51 " Time passed during each call, %: [6.66724,57.2857,34.9703,1.07672]" 17:23:51 " Element types: ["NIL"]" 17:23:52 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 2.11794e-005" 17:23:56 " (last output 0) 33334 shuffles run; avg. time per one shuffle: 0.000138267" 17:24:00 " (last output 0) 33334 shuffles run; avg. time per one shuffle: 0.000109618" 17:24:00 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 3.44964e-006" 17:24:00 " Time passed during each call, %: [7.77185,50.7377,40.2245,1.26586]" 17:24:00 " Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]" 17:24:01 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 2.12691e-005" 17:24:07 " (last output 29) 33334 shuffles run; avg. time per one shuffle: 0.000179367" 17:24:11 " (last output 29) 33334 shuffles run; avg. time per one shuffle: 0.000113457" 17:24:11 " (last output 30) 33334 shuffles run; avg. time per one shuffle: 3.42034e-006" 17:24:11 " Time passed during each call, %: [6.69865,56.4911,35.7331,1.07723]" 17:24:11 "Running tests for arrays of size 100" 17:24:11 " Element types: ["ARRAY"]" 17:24:11 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 2.19971e-005" 17:24:22 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.001072" 17:24:26 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000412994" 17:24:26 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 3.40576e-006" 17:24:26 " Time passed during each call, %: [1.45637,70.9748,27.3434,0.225487]" 17:24:26 " Element types: ["BOOL"]" 17:24:26 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 2.19971e-005" 17:24:30 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000417102" 17:24:34 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000373499" 17:24:34 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 3.49731e-006" 17:24:34 " Time passed during each call, %: [2.69541,51.1095,45.7666,0.428543]" 17:24:34 " Element types: ["CODE"]" 17:24:34 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 2.21985e-005" 17:24:41 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000655499" 17:24:45 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000361804" 17:24:45 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 3.49731e-006" 17:24:45 " Time passed during each call, %: [2.12833,62.8475,34.6888,0.335313]" 17:24:45 " Element types: ["OBJECT"]" 17:24:45 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 2.21008e-005" 17:24:51 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000632098" 17:24:55 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.0003737" 17:24:55 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 3.39966e-006" 17:24:55 " Time passed during each call, %: [2.14301,61.2915,36.2359,0.329648]" 17:24:55 " Element types: ["SCALAR"]" 17:24:55 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 2.21008e-005" 17:25:00 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000537103" 17:25:04 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.0003401" 17:25:04 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 3.39966e-006" 17:25:04 " Time passed during each call, %: [2.44829,59.4994,37.6757,0.376608]" 17:25:04 " Element types: ["SIDE"]" 17:25:04 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 2.21008e-005" 17:25:08 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000409296" 17:25:12 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000345703" 17:25:12 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 3.39966e-006" 17:25:12 " Time passed during each call, %: [2.83163,52.4402,44.2926,0.435575]" 17:25:12 " Element types: ["STRING"]" 17:25:12 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 2.19971e-005" 17:25:20 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000776599" 17:25:23 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 0.000372205" 17:25:24 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 3.39966e-006" 17:25:24 " Time passed during each call, %: [1.87337,66.1385,31.6986,0.28953]" 17:25:24 " Element types: ["NIL"]" 17:25:24 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 2.18994e-005" 17:25:28 " (last output 0) 10000 shuffles run; avg. time per one shuffle: 0.000399701" 17:25:31 " (last output 0) 10000 shuffles run; avg. time per one shuffle: 0.000368298" 17:25:31 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 3.39966e-006" 17:25:31 " Time passed during each call, %: [2.76055,50.3847,46.4262,0.428547]" 17:25:31 " Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]" 17:25:32 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 2.21008e-005" 17:25:38 " (last output 86) 10000 shuffles run; avg. time per one shuffle: 0.000602802" 17:25:41 " (last output 86) 10000 shuffles run; avg. time per one shuffle: 0.000353198" 17:25:41 " (last output 100) 10000 shuffles run; avg. time per one shuffle: 3.39966e-006" 17:25:41 " Time passed during each call, %: [2.25174,61.4163,35.9855,0.346374]" 17:25:41 "Running tests for arrays of size 301" 17:25:42 " Element types: ["ARRAY"]" 17:25:42 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 2.43737e-005" 17:26:03 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00632982" 17:26:07 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00135269" 17:26:07 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 3.60003e-006" 17:26:07 " Time passed during each call, %: [0.31611,82.0937,17.5435,0.04669]" 17:26:07 " Element types: ["BOOL"]" 17:26:07 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 2.37675e-005" 17:26:12 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.0014809" 17:26:16 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00104935" 17:26:16 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 3.30615e-006" 17:26:16 " Time passed during each call, %: [0.929391,57.9081,41.0332,0.129282]" 17:26:16 " Element types: ["CODE"]" 17:26:16 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 2.40798e-005" 17:26:26 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00320672" 17:26:30 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00114295" 17:26:30 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 3.32452e-006" 17:26:30 " Time passed during each call, %: [0.550133,73.2617,26.1122,0.0759528]" 17:26:30 " Element types: ["OBJECT"]" 17:26:30 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 2.40798e-005" 17:26:40 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00299307" 17:26:44 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00107824" 17:26:44 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 3.30615e-006" 17:26:44 " Time passed during each call, %: [0.587497,73.0249,26.307,0.0806632]" 17:26:44 " Element types: ["SCALAR"]" 17:26:44 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 2.40798e-005" 17:26:51 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00198134" 17:26:54 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00101293" 17:26:54 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 3.61839e-006" 17:26:54 " Time passed during each call, %: [0.796825,65.5645,33.5189,0.119736]" 17:26:54 " Element types: ["SIDE"]" 17:26:54 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 2.43737e-005" 17:26:59 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00142793" 17:27:02 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00105055" 17:27:02 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 3.30615e-006" 17:27:02 " Time passed during each call, %: [0.972553,56.9768,41.9187,0.131921]" 17:27:02 " Element types: ["STRING"]" 17:27:02 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 2.40614e-005" 17:27:17 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00448721" 17:27:21 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 0.00105297" 17:27:21 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 3.30615e-006" 17:27:21 " Time passed during each call, %: [0.432172,80.5958,18.9126,0.0593824]" 17:27:21 " Element types: ["NIL"]" 17:27:21 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 2.43737e-005" 17:27:25 " (last output 0) 3323 shuffles run; avg. time per one shuffle: 0.0013551" 17:27:29 " (last output 0) 3323 shuffles run; avg. time per one shuffle: 0.00106952" 17:27:29 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 3.30615e-006" 17:27:29 " Time passed during each call, %: [0.993911,55.2583,43.613,0.134818]" 17:27:29 " Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]" 17:27:29 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 2.43737e-005" 17:27:38 " (last output 267) 3323 shuffles run; avg. time per one shuffle: 0.00267892" 17:27:42 " (last output 267) 3323 shuffles run; avg. time per one shuffle: 0.00107492" 17:27:42 " (last output 301) 3323 shuffles run; avg. time per one shuffle: 3.61839e-006" 17:27:42 " Time passed during each call, %: [0.644494,70.8365,28.4233,0.0956784]" 17:27:42 "Running tests for arrays of size 1000" 17:27:42 " Element types: ["ARRAY"]" 17:27:43 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 3.20435e-005" 17:28:38 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.055978" 17:28:43 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.004492" 17:28:43 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 2.99072e-006" 17:28:43 " Time passed during each call, %: [0.05296,92.5179,7.42419,0.00494293]" 17:28:43 " Element types: ["BOOL"]" 17:28:43 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 3.19824e-005" 17:28:51 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.00840302" 17:28:55 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.00363098" 17:28:55 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 4.02832e-006" 17:28:55 " Time passed during each call, %: [0.264974,69.619,30.0827,0.0333746]" 17:28:55 " Element types: ["CODE"]" 17:28:55 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 3.19824e-005" 17:29:23 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.0276461" 17:29:27 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.00384998" 17:29:27 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 4.02832e-006" 17:29:27 " Time passed during each call, %: [0.101428,87.6761,12.2097,0.0127753]" 17:29:27 " Element types: ["OBJECT"]" 17:29:27 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 3.20435e-005" 17:29:51 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.023761" 17:29:54 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.00360297" 17:29:54 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 4.02832e-006" 17:29:54 " Time passed during each call, %: [0.116947,86.7188,13.1495,0.0147019]" 17:29:54 " Element types: ["SCALAR"]" 17:29:54 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 3.10059e-005" 17:30:06 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.01175" 17:30:10 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.00349896" 17:30:10 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 2.99072e-006" 17:30:10 " Time passed during each call, %: [0.202879,76.883,22.8945,0.019569]" 17:30:10 " Element types: ["SIDE"]" 17:30:10 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 3.19824e-005" 17:30:18 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.00796301" 17:30:21 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.00359198" 17:30:21 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 2.99072e-006" 17:30:21 " Time passed during each call, %: [0.275949,68.7061,30.9922,0.0258044]" 17:30:21 " Element types: ["STRING"]" 17:30:21 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 3.20435e-005" 17:31:00 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.038453" 17:31:04 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 0.00359796" 17:31:04 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 2.99072e-006" 17:31:04 " Time passed during each call, %: [0.076138,91.3677,8.54907,0.00710622]" 17:31:04 " Element types: ["NIL"]" 17:31:04 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 3.20435e-005" 17:31:11 " (last output 0) 1000 shuffles run; avg. time per one shuffle: 0.00702496" 17:31:14 " (last output 0) 1000 shuffles run; avg. time per one shuffle: 0.00353601" 17:31:14 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 4.02832e-006" 17:31:14 " Time passed during each call, %: [0.302381,66.2917,33.3679,0.0380136]" 17:31:14 " Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]" 17:31:14 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 3.20435e-005" 17:31:38 " (last output 880) 1000 shuffles run; avg. time per one shuffle: 0.023547" 17:31:42 " (last output 880) 1000 shuffles run; avg. time per one shuffle: 0.00370398" 17:31:42 " (last output 1000) 1000 shuffles run; avg. time per one shuffle: 2.99072e-006" 17:31:42 " Time passed during each call, %: [0.117435,86.297,13.5746,0.0109606]" 17:31:42 "Running tests for arrays of size 3010" 17:31:44 " Element types: ["ARRAY"]" 17:31:44 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.40702e-005" 17:34:13 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.446438" 17:34:18 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0145766" 17:34:18 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 2.93262e-006" 17:34:18 " Time passed during each call, %: [0.0117271,96.8262,3.16146,0.000636044]" 17:34:18 " Element types: ["BOOL"]" 17:34:18 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.42535e-005" 17:34:37 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0565376" 17:34:41 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0118016" 17:34:41 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 2.93262e-006" 17:34:41 " Time passed during each call, %: [0.0793221,82.6617,17.2547,0.00428768]" 17:34:41 " Element types: ["CODE"]" 17:34:41 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.38869e-005" 17:35:57 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.227495" 17:36:01 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0125677" 17:36:01 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 2.93262e-006" 17:36:01 " Time passed during each call, %: [0.0224417,94.7424,5.23394,0.00122131]" 17:36:01 " Element types: ["OBJECT"]" 17:36:01 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.42535e-005" 17:37:04 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.189754" 17:37:08 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0119578" 17:37:08 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 3.2992e-006" 17:37:08 " Time passed during each call, %: [0.0268889,94.045,5.92646,0.00163514]" 17:37:08 " Element types: ["SCALAR"]" 17:37:08 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.38869e-005" 17:37:35 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0806577" 17:37:39 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0115465" 17:37:39 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 3.2992e-006" 17:37:39 " Time passed during each call, %: [0.0584068,87.4231,12.5149,0.00357593]" 17:37:39 " Element types: ["SIDE"]" 17:37:39 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.38869e-005" 17:37:57 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0521922" 17:38:01 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0118108" 17:38:01 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 6.23182e-006" 17:38:01 " Time passed during each call, %: [0.0841154,81.47,18.4361,0.00972763]" 17:38:01 " Element types: ["STRING"]" 17:38:01 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.42535e-005" 17:39:52 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.331165" 17:39:56 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 0.0118346" 17:39:56 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 2.93262e-006" 17:39:56 " Time passed during each call, %: [0.0158147,96.5336,3.44974,0.000854849]" 17:39:56 " Element types: ["NIL"]" 17:39:56 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.42535e-005" 17:40:10 " (last output 0) 333 shuffles run; avg. time per one shuffle: 0.0439757" 17:40:14 " (last output 0) 333 shuffles run; avg. time per one shuffle: 0.0109852" 17:40:14 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 2.93262e-006" 17:40:14 " Time passed during each call, %: [0.0986101,79.9295,19.9666,0.00533028]" 17:40:15 " Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]" 17:40:15 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.71861e-005" 17:41:16 " (last output 2622) 333 shuffles run; avg. time per one shuffle: 0.183207" 17:41:20 " (last output 2622) 333 shuffles run; avg. time per one shuffle: 0.0120512" 17:41:20 " (last output 3010) 333 shuffles run; avg. time per one shuffle: 5.86524e-006" 17:41:20 " Time passed during each call, %: [0.029278,93.7978,6.16995,0.00300287]" 17:41:20 "Running tests for arrays of size 10000" 17:41:27 " Element types: ["ARRAY"]" 17:41:27 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.000129395" 17:49:20 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 4.72184" 17:49:26 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.0633496" 17:49:26 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0" 17:49:26 " Time passed during each call, %: [0.00270399,98.6735,1.32383,0]" 17:49:27 " Element types: ["BOOL"]" 17:49:27 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.000129395" 17:50:22 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.549231" 17:50:27 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.0519482" 17:50:27 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 9.76562e-006" 17:50:27 " Time passed during each call, %: [0.0215185,91.3378,8.63906,0.00162404]" 17:50:28 " Element types: ["CODE"]" 17:50:28 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.000131836" 17:54:28 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 2.39852" 17:54:33 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.056311" 17:54:33 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0" 17:54:33 " Time passed during each call, %: [0.00537018,97.7009,2.29377,0]" 17:54:34 " Element types: ["OBJECT"]" 17:54:34 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.000141602" 17:57:53 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 1.98791" 17:57:58 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.0525586" 17:57:58 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0" 17:57:58 " Time passed during each call, %: [0.00693918,97.4174,2.57563,0]" 17:57:59 " Element types: ["SCALAR"]" 17:57:59 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.000129395" 17:59:18 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.793972" 17:59:23 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.0513281" 17:59:23 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0" 17:59:23 " Time passed during each call, %: [0.0153052,93.9134,6.07125,0]" 17:59:24 " Element types: ["SIDE"]" 17:59:24 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.000129395" 18:00:14 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.501999" 18:00:20 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.0521606" 18:00:20 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0" 18:00:20 " Time passed during each call, %: [0.0233442,90.5663,9.41036,0]" 18:00:21 " Element types: ["STRING"]" 18:00:21 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.000141602" 18:06:24 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 3.62747" 18:06:29 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.0530005" 18:06:29 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 9.76562e-006" 18:06:29 " Time passed during each call, %: [0.00384722,98.5559,1.43999,0.000265326]" 18:06:30 " Element types: ["NIL"]" 18:06:30 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.00013916" 18:07:12 " (last output 0) 100 shuffles run; avg. time per one shuffle: 0.41541" 18:07:16 " (last output 0) 100 shuffles run; avg. time per one shuffle: 0.041311" 18:07:16 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0" 18:07:16 " Time passed during each call, %: [0.0304601,90.9272,9.04238,0]" 18:07:18 " Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]" 18:07:18 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0.00013916" 18:10:28 " (last output 8770) 100 shuffles run; avg. time per one shuffle: 1.90115" 18:10:33 " (last output 8770) 100 shuffles run; avg. time per one shuffle: 0.0533008" 18:10:33 " (last output 10000) 100 shuffles run; avg. time per one shuffle: 0" 18:10:33 " Time passed during each call, %: [0.00711966,97.2659,2.72695,0]" 18:10:33 "Running tests for arrays of size 30103" 18:10:56 " Element types: ["ARRAY"]" 18:10:56 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.00035903" 18:35:23 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 43.1455" 18:35:34 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.311739" 18:35:34 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0" 18:35:34 " Time passed during each call, %: [0.000826163,99.2818,0.717341,0]" 19:21:36 " Element types: ["BOOL"]" 19:21:36 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.000352972" 19:24:20 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 4.82397" 19:24:30 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.282117" 19:24:30 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0" 19:24:30 " Time passed during each call, %: [0.00691228,94.4684,5.52473,0]" 19:24:32 " Element types: ["CODE"]" 19:24:32 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.000352747" 19:36:47 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 21.615" 19:36:58 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.318264" 19:36:58 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 2.87224e-005" 19:36:58 " Time passed during each call, %: [0.00160825,98.5472,1.45103,0.000130951]" 19:37:01 " Element types: ["OBJECT"]" 19:37:01 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.00035185" 19:47:10 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 17.9152" 19:47:19 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.279616" 19:47:19 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0" 19:47:19 " Time passed during each call, %: [0.00193376,98.4613,1.53676,0]" 19:47:22 " Element types: ["SCALAR"]" 19:47:22 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.00035185" 19:51:19 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 6.98556" 19:51:28 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.274766" 19:51:28 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0" 19:51:28 " Time passed during each call, %: [0.00484596,96.2108,3.7843,0]" 19:51:31 " Element types: ["SIDE"]" 19:51:31 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.00035185" 19:54:01 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 4.40068" 19:54:10 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.275175" 19:54:10 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 3.23127e-005" 19:54:10 " Time passed during each call, %: [0.00752421,94.1072,5.88454,0.000690999]" 19:54:15 " Element types: ["STRING"]" 19:54:15 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.00035544" 20:12:58 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 33.0156" 20:13:07 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.279555" 20:13:07 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0" 20:13:07 " Time passed during each call, %: [0.00106753,99.1593,0.839618,0]" 20:13:10 " Element types: ["NIL"]" 20:13:10 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.00035185" 20:15:11 " (last output 0) 34 shuffles run; avg. time per one shuffle: 3.55742" 20:15:16 " (last output 0) 34 shuffles run; avg. time per one shuffle: 0.164702" 20:15:16 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0" 20:15:16 " Time passed during each call, %: [0.00945205,95.566,4.42452,0]" 20:15:22 " Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]" 20:15:22 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0.00035185" 20:25:05 " (last output 26457) 34 shuffles run; avg. time per one shuffle: 17.1633" 20:25:15 " (last output 26457) 34 shuffles run; avg. time per one shuffle: 0.279268" 20:25:15 " (last output 30103) 34 shuffles run; avg. time per one shuffle: 0" 20:25:15 " Time passed during each call, %: [0.00201715,98.3969,1.60104,0]" 5. Details on report output For each combination of array count, used element types, and tested function report contains a log line describing said parameters, count of elements in the output (some functions fail to shuffle arrays with nils correctly), how many times loop was run for given array count and how much time it took for average run of shuffle function. On big arrays some functions fail to do the task, probably because of insufficient memory for operation of their algorithm, I dunno. Those calls report 0 time, which of course os not correct. Also, I had to partially rerun tests because ArmA3 ran out of memory (on CBA's shuffle of 30k array of "CODE"). You can see it in timestamps. Still all functions were in fairly equal conditions. 6. Conclusions CBA shuffle sucks (sorry guys, but I've got numbers). Shuffles array of 30k "ARRAY" elements in 43 seconds. U WOT M8??? I had to limit test to 30k elements because of it. BIS shuffle does not work properly, but at least does it fast. When final array size is known, resize+sets work on par with pushBack on small arrays and better on big arrays. Much better. The bigger the array the better. Or, more precisely, it's pushBack who starts to work bad. The bigger the array, the worse. That doesn't mean biki lies about set and pushBack performance. It only considers single element insertion to the array's end position, not population of entire array. You can shuffle array in average O(N) time if use proper method. 7. Any questions? Share this post Link to post Share on other sites
pedeathtrian 99 Posted March 7, 2016 I have seriously shat my pants here, guys >_< But nobody noticed so I have a chance to fix it myself. I was so glad to replace the for loop with more efficient form that I didn't notice I put a mistake in it. Copypasta, copypasta everywhere. for "_i" from 0 to (cnt-1) do {and for "_i" from 0 to (cnt-2) do {should've had _cnt of course in "pdth_fnc_shuffle.sqf". Therefore all measures and conclusions involving this file are incorrect in previous report. I've fixed the testing code and rerun the experiment. In my attempts to figure out what slows down CBA's shuffle I wrote one more shuffle function, based on CBA's one but with resize+sets approach. It turned out that slow downs are caused by (unnecessary) stringifications of input array in WARNING macros when passed in old form. So unless you want your code to be slowed, you never use the form [elem0, elem1, elem2, ...] call CBA_fnc_shuffleInstead, you write [[elem0, elem1, elem2, ...]] call CBA_fnc_shuffle Exe info ===================================================================== == D:\Steam\steamapps\common\Arma 3\arma3.exe == "D:\Steam\steamapps\common\Arma 3\arma3.exe" -cpuCount=8 -skipintro -showScriptErrors -maxMem=2047 -cpuCount=8 -noPause -nosplash -world=VR -enableHT "-mod=D:\Steam\steamapps\common\Arma 3\@CBA_A3" Original output filename: Arma3Retail_DX11 Exe timestamp: 2016/03/02 14:35:06 Current time: 2016/03/08 00:52:02 Type: Public Build: Stable Version: 1.56.134787 Allocator: D:\Steam\steamapps\common\Arma 3\dll\tbb4malloc_bi.dll ===================================================================== I slightly changed the code layout and code generating arrays for input, so time measuring from this report are not to be compared with previous. Testing code is as follows. "mission.sqm": No changes. "test_shuffle.sqf": #define DEF_MAX_DEPTH 5 #define DEF_MAX_ELEMS 5 #define DEF_SHUFFLE_RUNS 500000 [] call compile preprocessFile "generate_stuff.sqf"; { _x enableSimulation false; } forEach (entities "All"); private ["_arrForShuffle", "_numEls", "_k", "_st", "_en", "_step", "_funcs", "_times", "_sum", "_runs", "_avg", "_typs", "_usedTypes", "_csh", "_rep"]; pdth_fnc_shuf = compile preprocessFile "pdth_fnc_shuffle.sqf"; cba_fnc_shuf = compile preprocessFile "fnc_shuffle.sqf"; cba_fnc_shuf_v = CBA_fnc_shuffle; bis_fnc_shuf = compile preprocessFile "bis_fnc_shuffle.sqf"; bis_fnc_shuf_v = BIS_fnc_arrayShuffle; _funcs = [pdth_fnc_shuf, cba_fnc_shuf, cba_fnc_shuf_v, bis_fnc_shuf, bis_fnc_shuf_v]; _usedTypes = []; { _usedTypes pushBack [_x]; // for each type separately } forEach generatedTypes; _usedTypes pushBack generatedTypes; // and for mixed arrays { _numEls = _x; diag_log format ["""Running tests for arrays of size %1""", _numEls]; { _typs = _x; _arrForShuffle = [DEF_MAX_DEPTH, DEF_MAX_ELEMS, _typs, _numEls] call fnc_generate_array; _times = []; _sum = 0; diag_log format [""" Element types: %1""", _typs]; { if (isNil "_x" || _x isEqualTo {}) then { diag_log format [""" Function %1 is not defined""", _forEachIndex]; } else { _runs = ceil (DEF_SHUFFLE_RUNS / _numEls); if (_runs < 5) then {_runs = 5;}; if (_forEachIndex == 1 || _forEachIndex == 2) then { _st = diag_tickTime; for "_k" from 1 to _runs do { _csh = count ([_arrForShuffle] call _x); }; _en = diag_tickTime; } else { _st = diag_tickTime; for "_k" from 1 to _runs do { _csh = count (_arrForShuffle call _x); }; _en = diag_tickTime; }; _step = _en - _st; _avg = _step / _runs; _times pushBack _step; _sum = _sum + _step; diag_log format [""" (last output %1) %2 shuffles run; avg. time per one shuffle: %3""", _csh, _runs, _avg]; }; } forEach _funcs; _arrForShuffle = nil; // release array, so memory will be collected (?) { _times set [_forEachIndex, 100*_x / _sum]; } forEach _times; diag_log format [""" Time passed during each call, %1: %2""", "%", _times]; } forEach _usedTypes; } forEach [3, 10, 30, 100, 301, 1000, 3010, 10000, 30103, 100000, 301030/*, 1000000, 3010300, 9999999*/]; { _x enableSimulation true; } forEach (entities "All"); endMission "END1"; I was able to extend testing to 300k arrays. Further attempts were running out of memory on input initialization stage. Tested functions defined in following order (same in report output) pdth_fnc_shuf = compile preprocessFile "pdth_fnc_shuffle.sqf"; cba_fnc_shuf = compile preprocessFile "fnc_shuffle.sqf"; cba_fnc_shuf_v = CBA_fnc_shuffle; bis_fnc_shuf = compile preprocessFile "bis_fnc_shuffle.sqf"; bis_fnc_shuf_v = BIS_fnc_arrayShuffle; _funcs = [pdth_fnc_shuf, cba_fnc_shuf, cba_fnc_shuf_v, bis_fnc_shuf, bis_fnc_shuf_v]; "generate_stuff.sqf": #define DEF_MAX_DEPTH 5 #define DEF_MAX_ELEMS 5 #define DEF_MIN_STRLEN 7 #define DEF_MAX_STRLEN 63 generatedTypes = ["ARRAY", "BOOL", "CODE", "OBJECT", "SCALAR", "SIDE", "STRING", "NIL"]; fnc_generate_bool = { 0.5 > (random(1)); }; fnc_generate_scalar = { random (1e5) - 2e5; }; fnc_generate_string = { private ["_arr", "_i", "_count"]; _count = DEF_MIN_STRLEN + 1 + floor random(DEF_MAX_STRLEN-DEF_MIN_STRLEN); _arr = []; for "_i" from 1 to _count do { _arr pushBack (32 + floor random 95); // ascii, without 127 }; toString _arr; }; fnc_generate_code = { compile (["if (true) then {2+2} else {5}", "{ _x = _x + 1 } forEach [1,2,3]", "a = 42"] call BIS_fnc_selectRandom); }; fnc_generate_object = { (entities "All") call BIS_fnc_selectRandom; }; fnc_generate_side = { [west, east, resistance] call BIS_fnc_selectRandom }; fnc_generate_type = { private ["_type", "_types"]; _types = [_this, 2, generatedTypes, ["",[]]] call BIS_fnc_param; if ((typeName _types) == "ARRAY") then { _type = _types call BIS_fnc_selectRandom; if (_type == "ARRAY" && ((count _types) == 1)) then { _types = generatedTypes; }; } else { if ((typeName _types) == "STRING") then { _type = _types; if (_type == "ARRAY") then { _types = generatedTypes; }; }; }; switch _type do { case "ARRAY": { private ["_maxDepth", "_maxElems"]; _maxDepth = [_this, 0, DEF_MAX_DEPTH, [0]] call BIS_fnc_param; _maxElems = [_this, 1, DEF_MAX_ELEMS, [0]] call BIS_fnc_param; if (_maxDepth < 1) then { _maxDepth = DEF_MAX_DEPTH; }; if (_maxElems < 1) then { _maxElems = DEF_MAX_ELEMS; }; [_maxDepth, _maxElems, _types] call fnc_generate_array; }; case "BOOL": { call fnc_generate_bool; }; case "CODE": { call fnc_generate_code; }; case "OBJECT": { call fnc_generate_object; }; case "SCALAR": { call fnc_generate_scalar; }; case "SIDE": { call fnc_generate_side; }; case "STRING": { call fnc_generate_string; }; default {nil}; }; }; fnc_generate_array = { private ["_maxDepth", "_maxElems", "_i", "_cnt", "_types", "_ret"]; _maxDepth = [_this, 0, DEF_MAX_DEPTH, [0]] call BIS_fnc_param; _maxElems = [_this, 1, DEF_MAX_ELEMS, [0]] call BIS_fnc_param; _types = [_this, 2, generatedTypes, [[]]] call BIS_fnc_param; _cnt = [_this, 3, DEF_MAX_ELEMS, [0]] call BIS_fnc_param; _ret = []; if (_maxDepth < 1) then { _maxDepth = DEF_MAX_DEPTH; }; if (_maxElems < 1) then { _maxElems = DEF_MAX_ELEMS; }; if (_cnt < 1) then { _cnt = floor random (1+_maxElems); }; _ret resize _cnt; for "_i" from 0 to (_cnt-1) do { _ret set [_i, [_maxDepth-1, _maxElems, _types] call fnc_generate_type]; }; _ret }; "pdth_fnc_shuffle.sqf": /// --- validate general input #include "\A3\functions_f\paramsCheck.inc" paramsCheck(_this,isEqualType,[]) private ["_cnt", "_result"]; _cnt = count _this; _result = []; if (_cnt > 0) then { private ["_i", "_idxs"]; _idxs = []; _idxs resize _cnt; for "_i" from 0 to (_cnt-1) do { _idxs set [_i, _i]; }; _result resize _cnt; for "_i" from 0 to (_cnt-2) do { _result set [_i, _this select (_idxs deleteAt floor random (_cnt-_i))]; }; _result set [_cnt-1, _this select (_idxs select 0)]; }; _result "fnc_shuffle.sqf": //#include "script_component.hpp" #include "\x\cba\addons\arrays\script_component.hpp" SCRIPT(pdth_shuffle); scopeName "shuffle"; private ["_shuffledArray", "_tempArray", "_cnt"]; // Support the deprecated parameter style: [1, 2, 3, 4, 5] call CBA_fnc_shuffle. _tempArray = if (count _this != 1) then { WARNING("CBA_fnc_shuffle requires an array as first parameter, not just a direct array: " + str _this); +_this } else { if (IS_ARRAY(_this select 0)) then { +(_this select 0) // Correct params passed. } else { WARNING("CBA_fnc_shuffle requires an array as first parameter, not just a direct array: " + str _this); (+_this) breakOut "shuffle"; // _this only has one element now, so why shuffle? return copy }; }; _cnt = count _tempArray; _shuffledArray = []; if (_cnt > 0) then { _shuffledArray resize _cnt; for "_i" from 0 to (_cnt-2) do { _shuffledArray set [_i, _tempArray deleteAt floor random (_cnt-_i)]; }; _shuffledArray set [_cnt-1, _tempArray select 0]; // omit extra random call }; _shuffledArray "bis_fnc_shuffle.sqf": No changes Report (Fixed) 0:53:12 ""Running tests for arrays of size 3"" 0:53:12 "" Element types: ["ARRAY"]"" 0:53:17 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.99519e-005"" 0:53:23 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 3.1284e-005"" 0:53:28 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 3.24839e-005"" 0:53:31 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.96379e-005"" 0:53:34 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.8504e-005"" 0:53:34 "" Time passed during each call, %: [22.7146,23.7248,24.6349,14.8928,14.0329]"" 0:53:34 "" Element types: ["BOOL"]"" 0:53:39 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.9436e-005"" 0:53:44 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.83979e-005"" 0:53:49 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 3.1722e-005"" 0:53:52 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.6902e-005"" 0:53:55 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.7928e-005"" 0:53:55 "" Time passed during each call, %: [23.6651,22.8305,25.5029,13.5884,14.4132]"" 0:53:55 "" Element types: ["CODE"]"" 0:54:00 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.9484e-005"" 0:54:05 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.87699e-005"" 0:54:10 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 3.1668e-005"" 0:54:13 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.725e-005"" 0:54:16 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.7976e-005"" 0:54:16 "" Time passed during each call, %: [23.5593,22.9888,25.3045,13.7837,14.3638]"" 0:54:16 "" Element types: ["OBJECT"]"" 0:54:21 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.93099e-005"" 0:54:26 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.8584e-005"" 0:54:31 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 3.1674e-005"" 0:54:34 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.69499e-005"" 0:54:37 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.7952e-005"" 0:54:37 "" Time passed during each call, %: [23.5478,22.9646,25.4471,13.6177,14.4228]"" 0:54:37 "" Element types: ["SCALAR"]"" 0:54:42 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.93099e-005"" 0:54:46 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.84099e-005"" 0:54:52 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 3.1764e-005"" 0:54:54 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.6698e-005"" 0:54:57 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.7922e-005"" 0:54:57 "" Time passed during each call, %: [23.6173,22.8921,25.5947,13.4549,14.4411]"" 0:54:57 "" Element types: ["SIDE"]"" 0:55:02 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.94059e-005"" 0:55:07 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.85779e-005"" 0:55:12 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 3.17279e-005"" 0:55:15 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.686e-005"" 0:55:18 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.7982e-005"" 0:55:18 "" Time passed during each call, %: [23.609,22.9443,25.4733,13.5363,14.4372]"" 0:55:18 "" Element types: ["STRING"]"" 0:55:23 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.946e-005"" 0:55:28 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.844e-005"" 0:55:33 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 3.17279e-005"" 0:55:36 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.69199e-005"" 0:55:39 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.8006e-005"" 0:55:39 "" Time passed during each call, %: [23.6524,22.8335,25.4733,13.5844,14.4564]"" 0:55:39 "" Element types: ["NIL"]"" 0:55:44 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.94239e-005"" 0:55:49 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.8584e-005"" 0:55:54 "" (last output 0) 166667 shuffles run; avg. time per one shuffle: 3.17879e-005"" 0:55:57 "" (last output 0) 166667 shuffles run; avg. time per one shuffle: 1.683e-005"" 0:55:59 "" (last output 0) 166667 shuffles run; avg. time per one shuffle: 1.10219e-005"" 0:55:59 "" Time passed during each call, %: [25.0102,24.2963,27.0195,14.3054,9.36858]"" 0:55:59 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 0:56:03 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.95439e-005"" 0:56:08 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 2.8764e-005"" 0:56:14 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 3.20639e-005"" 0:56:16 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.7124e-005"" 0:56:19 "" (last output 3) 166667 shuffles run; avg. time per one shuffle: 1.8024e-005"" 0:56:19 "" Time passed during each call, %: [23.5373,22.9159,25.5449,13.6425,14.3595]"" 0:56:19 ""Running tests for arrays of size 10"" 0:56:19 "" Element types: ["ARRAY"]"" 0:56:23 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.64398e-005"" 0:56:26 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.836e-005"" 0:56:29 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.62799e-005"" 0:56:32 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.74799e-005"" 0:56:34 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.69604e-005"" 0:56:34 "" Time passed during each call, %: [23.2698,23.9423,19.7114,20.1316,12.945]"" 0:56:34 "" Element types: ["BOOL"]"" 0:56:37 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.21405e-005"" 0:56:39 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5e-005"" 0:56:42 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.21796e-005"" 0:56:44 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.92804e-005"" 0:56:46 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.28198e-005"" 0:56:46 "" Time passed during each call, %: [26.2839,21.1488,22.0707,16.6146,13.882]"" 0:56:46 "" Element types: ["CODE"]"" 0:56:49 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.19e-005"" 0:56:51 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.11395e-005"" 0:56:54 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.25e-005"" 0:56:56 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 4.04803e-005"" 0:56:58 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.29401e-005"" 0:56:58 "" Time passed during each call, %: [25.9039,21.4009,21.9702,16.9402,13.7848]"" 0:56:58 "" Element types: ["OBJECT"]"" 0:57:01 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.21399e-005"" 0:57:03 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.01001e-005"" 0:57:06 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.22595e-005"" 0:57:08 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.94403e-005"" 0:57:09 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.29797e-005"" 0:57:09 "" Time passed during each call, %: [26.2283,21.1465,22.0579,16.6471,13.9202]"" 0:57:09 "" Element types: ["SCALAR"]"" 0:57:12 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.16803e-005"" 0:57:15 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 4.94995e-005"" 0:57:18 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.172e-005"" 0:57:19 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.86005e-005"" 0:57:21 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.26801e-005"" 0:57:21 "" Time passed during each call, %: [26.3388,21.1374,22.0855,16.4832,13.9551]"" 0:57:21 "" Element types: ["SIDE"]"" 0:57:24 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.20001e-005"" 0:57:27 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 4.948e-005"" 0:57:29 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.21399e-005"" 0:57:31 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.90204e-005"" 0:57:33 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.29596e-005"" 0:57:33 "" Time passed during each call, %: [26.3158,21.0017,22.1307,16.5621,13.9896]"" 0:57:33 "" Element types: ["STRING"]"" 0:57:36 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.18201e-005"" 0:57:38 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 4.96399e-005"" 0:57:41 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.22803e-005"" 0:57:43 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.92596e-005"" 0:57:45 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 3.31403e-005"" 0:57:45 "" Time passed during each call, %: [26.1794,21.0214,22.1395,16.6256,14.0341]"" 0:57:45 "" Element types: ["NIL"]"" 0:57:48 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.18799e-005"" 0:57:50 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 4.94598e-005"" 0:57:53 "" (last output 0) 50000 shuffles run; avg. time per one shuffle: 5.20001e-005"" 0:57:55 "" (last output 0) 50000 shuffles run; avg. time per one shuffle: 3.89801e-005"" 0:57:55 "" (last output 0) 50000 shuffles run; avg. time per one shuffle: 1.10602e-005"" 0:57:55 "" Time passed during each call, %: [28.9998,23.1792,24.3697,18.2679,5.18332]"" 0:57:55 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 0:57:59 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 6.29797e-005"" 0:58:01 "" (last output 10) 50000 shuffles run; avg. time per one shuffle: 5.23401e-005"" 0:58:04 "" (last output 6) 50000 shuffles run; avg. time per one shuffle: 5.27802e-005"" 0:58:06 "" (last output 6) 50000 shuffles run; avg. time per one shuffle: 4.13397e-005"" 0:58:07 "" (last output 6) 50000 shuffles run; avg. time per one shuffle: 2.48804e-005"" 0:58:07 "" Time passed during each call, %: [26.8777,22.337,22.5248,17.6424,10.6181]"" 0:58:07 ""Running tests for arrays of size 30"" 0:58:07 "" Element types: ["ARRAY"]"" 0:58:10 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000162897"" 0:58:12 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000146278"" 0:58:14 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000117357"" 0:58:17 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000136618"" 0:58:18 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 8.28572e-005"" 0:58:18 "" Time passed during each call, %: [25.2159,22.6434,18.1666,21.148,12.8261]"" 0:58:18 "" Element types: ["BOOL"]"" 0:58:20 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000154857"" 0:58:22 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000110337"" 0:58:24 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000109438"" 0:58:26 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000103138"" 0:58:27 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 7.58975e-005"" 0:58:27 "" Time passed during each call, %: [27.9693,19.9284,19.7661,18.6281,13.7082]"" 0:58:27 "" Element types: ["CODE"]"" 0:58:30 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000156116"" 0:58:32 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000115199"" 0:58:33 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000110337"" 0:58:35 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000106558"" 0:58:37 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 7.60788e-005"" 0:58:37 "" Time passed during each call, %: [27.666,20.4148,19.5533,18.8836,13.4822]"" 0:58:37 "" Element types: ["OBJECT"]"" 0:58:39 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000155157"" 0:58:41 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000111178"" 0:58:43 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000110097"" 0:58:45 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000104157"" 0:58:46 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 7.60788e-005"" 0:58:46 "" Time passed during each call, %: [27.8724,19.972,19.7779,18.7109,13.6668]"" 0:58:46 "" Element types: ["SCALAR"]"" 0:58:48 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000156896"" 0:58:50 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000112619"" 0:58:52 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000109017"" 0:58:54 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000104637"" 0:58:55 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 7.49985e-005"" 0:58:55 "" Time passed during each call, %: [28.1092,20.1765,19.5312,18.7466,13.4366]"" 0:58:55 "" Element types: ["SIDE"]"" 0:58:58 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000155217"" 0:59:00 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000110277"" 0:59:01 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000110037"" 0:59:03 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000102898"" 0:59:04 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 7.55386e-005"" 0:59:04 "" Time passed during each call, %: [28.0192,19.9067,19.8634,18.5747,13.6359]"" 0:59:04 "" Element types: ["STRING"]"" 0:59:07 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000154977"" 0:59:09 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000110817"" 0:59:11 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000110819"" 0:59:12 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000103198"" 0:59:14 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 7.63791e-005"" 0:59:14 "" Time passed during each call, %: [27.8641,19.9243,19.9246,18.5545,13.7326]"" 0:59:14 "" Element types: ["NIL"]"" 0:59:16 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000154796"" 0:59:18 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000110398"" 0:59:20 "" (last output 0) 16667 shuffles run; avg. time per one shuffle: 0.000109019"" 0:59:22 "" (last output 0) 16667 shuffles run; avg. time per one shuffle: 0.000102178"" 0:59:22 "" (last output 0) 16667 shuffles run; avg. time per one shuffle: 1.10392e-005"" 0:59:22 "" Time passed during each call, %: [31.7576,22.6489,22.3661,20.9626,2.26478]"" 0:59:22 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 0:59:24 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000160857"" 0:59:26 "" (last output 30) 16667 shuffles run; avg. time per one shuffle: 0.000115858"" 0:59:28 "" (last output 29) 16667 shuffles run; avg. time per one shuffle: 0.000111839"" 0:59:30 "" (last output 29) 16667 shuffles run; avg. time per one shuffle: 0.000107876"" 0:59:31 "" (last output 29) 16667 shuffles run; avg. time per one shuffle: 7.51798e-005"" 0:59:31 "" Time passed during each call, %: [28.141,20.2687,19.5656,18.8724,13.1523]"" 0:59:31 ""Running tests for arrays of size 100"" 0:59:32 "" Element types: ["ARRAY"]"" 0:59:34 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000526196"" 0:59:37 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000521204"" 0:59:39 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000352997"" 0:59:41 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000515399"" 0:59:42 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000264801"" 0:59:42 "" Time passed during each call, %: [24.1308,23.9019,16.1881,23.6357,12.1435]"" 0:59:42 "" Element types: ["BOOL"]"" 0:59:45 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.0004862"" 0:59:47 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.0003284"" 0:59:48 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000315002"" 0:59:50 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000332397"" 0:59:51 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000226404"" 0:59:51 "" Time passed during each call, %: [28.7964,19.4503,18.6568,19.6871,13.4093]"" 0:59:51 "" Element types: ["CODE"]"" 0:59:53 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000488599"" 0:59:55 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000341602"" 0:59:57 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000317596"" 0:59:58 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000344"" 1:00:00 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.0002302"" 1:00:00 "" Time passed during each call, %: [28.374,19.8375,18.4435,19.9768,13.3682]"" 1:00:00 "" Element types: ["OBJECT"]"" 1:00:02 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000481598"" 1:00:04 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000329199"" 1:00:05 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000313"" 1:00:07 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000329999"" 1:00:08 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000227399"" 1:00:08 "" Time passed during each call, %: [28.6462,19.5813,18.6177,19.6288,13.526]"" 1:00:08 "" Element types: ["SCALAR"]"" 1:00:10 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000481201"" 1:00:12 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000323401"" 1:00:14 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000311603"" 1:00:15 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000324194"" 1:00:16 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000225403"" 1:00:16 "" Time passed during each call, %: [28.8871,19.4141,18.7059,19.4618,13.5312]"" 1:00:16 "" Element types: ["SIDE"]"" 1:00:19 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000481201"" 1:00:20 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.0003224"" 1:00:22 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.0003138"" 1:00:24 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000325"" 1:00:25 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000226801"" 1:00:25 "" Time passed during each call, %: [28.8282,19.3146,18.7994,19.4704,13.5874]"" 1:00:25 "" Element types: ["STRING"]"" 1:00:27 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000481201"" 1:00:29 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.0003284"" 1:00:30 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000316595"" 1:00:32 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000331403"" 1:00:33 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000228998"" 1:00:33 "" Time passed during each call, %: [28.5309,19.4711,18.7713,19.6492,13.5775]"" 1:00:33 "" Element types: ["NIL"]"" 1:00:36 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000481006"" 1:00:37 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000325391"" 1:00:39 "" (last output 0) 5000 shuffles run; avg. time per one shuffle: 0.000312207"" 1:00:40 "" (last output 0) 5000 shuffles run; avg. time per one shuffle: 0.000327405"" 1:00:40 "" (last output 0) 5000 shuffles run; avg. time per one shuffle: 1.11938e-005"" 1:00:40 "" Time passed during each call, %: [33.0089,22.3298,21.4251,22.468,0.768174]"" 1:00:40 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 1:00:43 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000492004"" 1:00:45 "" (last output 100) 5000 shuffles run; avg. time per one shuffle: 0.000353003"" 1:00:46 "" (last output 90) 5000 shuffles run; avg. time per one shuffle: 0.000323999"" 1:00:48 "" (last output 90) 5000 shuffles run; avg. time per one shuffle: 0.000355603"" 1:00:49 "" (last output 90) 5000 shuffles run; avg. time per one shuffle: 0.000212598"" 1:00:49 "" Time passed during each call, %: [28.3216,20.3201,18.6506,20.4698,12.2379]"" 1:00:49 ""Running tests for arrays of size 301"" 1:00:50 "" Element types: ["ARRAY"]"" 1:00:52 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.0015698"" 1:00:55 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00148857"" 1:00:57 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00103191"" 1:00:59 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.0015066"" 1:01:00 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000781595"" 1:01:00 "" Time passed during each call, %: [24.6109,23.3374,16.178,23.6201,12.2537]"" 1:01:00 "" Element types: ["BOOL"]"" 1:01:03 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00143139"" 1:01:04 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000948248"" 1:01:06 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000903151"" 1:01:07 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000984348"" 1:01:09 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000661251"" 1:01:09 "" Time passed during each call, %: [29.0437,19.2405,18.3255,19.973,13.4172]"" 1:01:09 "" Element types: ["CODE"]"" 1:01:11 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00144163"" 1:01:13 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000998193"" 1:01:14 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000912149"" 1:01:16 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.0010373"" 1:01:17 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000670285"" 1:01:17 "" Time passed during each call, %: [28.4932,19.7288,18.0282,20.5018,13.2479]"" 1:01:17 "" Element types: ["OBJECT"]"" 1:01:19 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00142959"" 1:01:21 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000957282"" 1:01:23 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000905538"" 1:01:24 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000994594"" 1:01:25 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000663638"" 1:01:25 "" Time passed during each call, %: [28.8768,19.3365,18.2913,20.0902,13.4051]"" 1:01:25 "" Element types: ["SCALAR"]"" 1:01:28 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00144762"" 1:01:29 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000950085"" 1:01:31 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000901903"" 1:01:32 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00097715"" 1:01:34 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000661251"" 1:01:34 "" Time passed during each call, %: [29.3159,19.2402,18.2645,19.7883,13.391]"" 1:01:34 "" Element types: ["SIDE"]"" 1:01:36 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00142841"" 1:01:37 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000943438"" 1:01:39 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000905538"" 1:01:41 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000979537"" 1:01:42 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00066305"" 1:01:42 "" Time passed during each call, %: [29.0329,19.1756,18.4053,19.9094,13.4767]"" 1:01:42 "" Element types: ["STRING"]"" 1:01:44 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.001429"" 1:01:46 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000950672"" 1:01:47 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000912736"" 1:01:49 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000987359"" 1:01:50 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000670873"" 1:01:50 "" Time passed during each call, %: [28.865,19.203,18.4367,19.9441,13.5512]"" 1:01:50 "" Element types: ["NIL"]"" 1:01:52 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00142779"" 1:01:54 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.000947661"" 1:01:55 "" (last output 0) 1662 shuffles run; avg. time per one shuffle: 0.000910937"" 1:01:57 "" (last output 0) 1662 shuffles run; avg. time per one shuffle: 0.000984348"" 1:01:57 "" (last output 0) 1662 shuffles run; avg. time per one shuffle: 1.14579e-005"" 1:01:57 "" Time passed during each call, %: [33.3425,22.1303,21.2727,22.987,0.26757]"" 1:01:57 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 1:02:00 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00148016"" 1:02:01 "" (last output 301) 1662 shuffles run; avg. time per one shuffle: 0.00103488"" 1:02:03 "" (last output 267) 1662 shuffles run; avg. time per one shuffle: 0.000928417"" 1:02:05 "" (last output 267) 1662 shuffles run; avg. time per one shuffle: 0.0010698"" 1:02:06 "" (last output 267) 1662 shuffles run; avg. time per one shuffle: 0.000607083"" 1:02:06 "" Time passed during each call, %: [28.9074,20.2111,18.1319,20.8932,11.8563]"" 1:02:06 ""Running tests for arrays of size 1000"" 1:02:08 "" Element types: ["ARRAY"]"" 1:02:11 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.0052959"" 1:02:13 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00500195"" 1:02:15 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00342407"" 1:02:17 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00517798"" 1:02:19 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00269592"" 1:02:19 "" Time passed during each call, %: [24.5228,23.1617,15.8553,23.9768,12.4835]"" 1:02:19 "" Element types: ["BOOL"]"" 1:02:21 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00476599"" 1:02:23 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00312402"" 1:02:24 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00298206"" 1:02:26 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00331995"" 1:02:27 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00223608"" 1:02:27 "" Time passed during each call, %: [29.0112,19.0163,18.1522,20.2089,13.6113]"" 1:02:27 "" Element types: ["CODE"]"" 1:02:29 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00477002"" 1:02:31 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00332397"" 1:02:33 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00302002"" 1:02:34 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00351807"" 1:02:35 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.0022699"" 1:02:35 "" Time passed during each call, %: [28.2217,19.6662,17.8678,20.8145,13.4298]"" 1:02:36 "" Element types: ["OBJECT"]"" 1:02:38 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00478394"" 1:02:40 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.003146"" 1:02:41 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00297803"" 1:02:43 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00334607"" 1:02:44 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00225"" 1:02:44 "" Time passed during each call, %: [28.9865,19.062,18.0442,20.2743,13.633]"" 1:02:44 "" Element types: ["SCALAR"]"" 1:02:46 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00475598"" 1:02:48 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00314001"" 1:02:49 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00296204"" 1:02:51 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00331799"" 1:02:52 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00221997"" 1:02:52 "" Time passed during each call, %: [29.007,19.1511,18.0656,20.2366,13.5397]"" 1:02:52 "" Element types: ["SIDE"]"" 1:02:55 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00475598"" 1:02:56 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00311804"" 1:02:58 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00296997"" 1:02:59 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00334204"" 1:03:00 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00224792"" 1:03:00 "" Time passed during each call, %: [28.94,18.9732,18.0722,20.3362,13.6785]"" 1:03:01 "" Element types: ["STRING"]"" 1:03:03 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00477197"" 1:03:05 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.003146"" 1:03:06 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00301404"" 1:03:08 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00336804"" 1:03:09 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00228198"" 1:03:09 "" Time passed during each call, %: [28.778,18.9723,18.1765,20.3114,13.7618]"" 1:03:09 "" Element types: ["NIL"]"" 1:03:11 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00481995"" 1:03:13 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00314612"" 1:03:14 "" (last output 0) 500 shuffles run; avg. time per one shuffle: 0.00300989"" 1:03:16 "" (last output 0) 500 shuffles run; avg. time per one shuffle: 0.00327209"" 1:03:16 "" (last output 0) 500 shuffles run; avg. time per one shuffle: 1.79443e-005"" 1:03:16 "" Time passed during each call, %: [33.7863,22.0533,21.0983,22.9363,0.125784]"" 1:03:16 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 1:03:19 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00489404"" 1:03:21 "" (last output 1000) 500 shuffles run; avg. time per one shuffle: 0.00345996"" 1:03:22 "" (last output 892) 500 shuffles run; avg. time per one shuffle: 0.00307007"" 1:03:24 "" (last output 892) 500 shuffles run; avg. time per one shuffle: 0.00363196"" 1:03:25 "" (last output 892) 500 shuffles run; avg. time per one shuffle: 0.00206604"" 1:03:25 "" Time passed during each call, %: [28.5832,20.2076,17.9305,21.2121,12.0665]"" 1:03:25 ""Running tests for arrays of size 3010"" 1:03:31 "" Element types: ["ARRAY"]"" 1:03:34 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0163534"" 1:03:37 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0168801"" 1:03:38 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0107188"" 1:03:41 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0180777"" 1:03:43 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00871268"" 1:03:43 "" Time passed during each call, %: [23.1167,23.8612,15.1518,25.5542,12.316]"" 1:03:43 "" Element types: ["BOOL"]"" 1:03:45 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0146225"" 1:03:47 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00968887"" 1:03:49 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00922143"" 1:03:50 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0110839"" 1:03:52 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00733518"" 1:03:52 "" Time passed during each call, %: [28.1462,18.6497,17.7499,21.335,14.1192]"" 1:03:52 "" Element types: ["CODE"]"" 1:03:54 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0146704"" 1:03:56 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0102159"" 1:03:58 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00932924"" 1:04:00 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0115689"" 1:04:01 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00740718"" 1:04:01 "" Time passed during each call, %: [27.5802,19.2058,17.5389,21.7495,13.9255]"" 1:04:01 "" Element types: ["OBJECT"]"" 1:04:04 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0145867"" 1:04:05 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00979048"" 1:04:07 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00935921"" 1:04:09 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0111497"" 1:04:10 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00739512"" 1:04:10 "" Time passed during each call, %: [27.9004,18.7266,17.9017,21.3264,14.1449]"" 1:04:10 "" Element types: ["SCALAR"]"" 1:04:13 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0146707"" 1:04:14 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00965269"" 1:04:16 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00913773"" 1:04:17 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0109162"" 1:04:19 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00731143"" 1:04:19 "" Time passed during each call, %: [28.3828,18.6747,17.6784,21.119,14.1451]"" 1:04:19 "" Element types: ["SIDE"]"" 1:04:21 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0146166"" 1:04:23 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00967681"" 1:04:25 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0092693"" 1:04:26 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0110302"" 1:04:28 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00734724"" 1:04:28 "" Time passed during each call, %: [28.1413,18.6307,17.8461,21.2363,14.1456]"" 1:04:28 "" Element types: ["STRING"]"" 1:04:31 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0145867"" 1:04:32 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00977257"" 1:04:34 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0093413"" 1:04:36 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0111497"" 1:04:37 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.007443"" 1:04:37 "" Time passed during each call, %: [27.894,18.688,17.8633,21.3215,14.2332]"" 1:04:37 "" Element types: ["NIL"]"" 1:04:40 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.014647"" 1:04:41 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.00968851"" 1:04:43 "" (last output 0) 167 shuffles run; avg. time per one shuffle: 0.00935921"" 1:04:44 "" (last output 0) 167 shuffles run; avg. time per one shuffle: 0.0101497"" 1:04:44 "" (last output 0) 167 shuffles run; avg. time per one shuffle: 7.19996e-005"" 1:04:44 "" Time passed during each call, %: [33.3519,22.0612,21.3114,23.1115,0.163947]"" 1:04:45 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 1:04:48 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0151137"" 1:04:50 "" (last output 3010) 167 shuffles run; avg. time per one shuffle: 0.0107067"" 1:04:51 "" (last output 2657) 167 shuffles run; avg. time per one shuffle: 0.00958691"" 1:04:53 "" (last output 2657) 167 shuffles run; avg. time per one shuffle: 0.011892"" 1:04:55 "" (last output 2657) 167 shuffles run; avg. time per one shuffle: 0.00665868"" 1:04:55 "" Time passed during each call, %: [28.0101,19.8427,17.7673,22.0393,12.3405]"" 1:04:55 ""Running tests for arrays of size 10000"" 1:05:15 "" Element types: ["ARRAY"]"" 1:05:18 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0613794"" 1:05:21 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0676001"" 1:05:23 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0422803"" 1:05:27 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0801794"" 1:05:29 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0396399"" 1:05:29 "" Time passed during each call, %: [21.0868,23.224,14.5254,27.5456,13.6183]"" 1:05:30 "" Element types: ["BOOL"]"" 1:05:33 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0529199"" 1:05:34 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0364404"" 1:05:36 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0350195"" 1:05:39 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0496997"" 1:05:40 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.03328"" 1:05:40 "" Time passed during each call, %: [25.5208,17.5735,16.8883,23.9679,16.0494]"" 1:05:41 "" Element types: ["CODE"]"" 1:05:44 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0531396"" 1:05:46 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0391602"" 1:05:48 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0354602"" 1:05:50 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0521399"" 1:05:52 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0333203"" 1:05:52 "" Time passed during each call, %: [24.9224,18.3661,16.6308,24.4535,15.6272]"" 1:05:53 "" Element types: ["OBJECT"]"" 1:05:55 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0527795"" 1:05:57 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0367004"" 1:05:59 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0351196"" 1:06:01 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0496191"" 1:06:03 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0330408"" 1:06:03 "" Time passed during each call, %: [25.4654,17.7075,16.9448,23.9406,15.9417]"" 1:06:04 "" Element types: ["SCALAR"]"" 1:06:06 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0528992"" 1:06:08 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0363"" 1:06:10 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.035"" 1:06:12 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0491406"" 1:06:14 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0328003"" 1:06:14 "" Time passed during each call, %: [25.6618,17.6094,16.9787,23.8385,15.9116]"" 1:06:15 "" Element types: ["SIDE"]"" 1:06:17 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0527209"" 1:06:19 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0362195"" 1:06:21 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0351404"" 1:06:24 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0491992"" 1:06:25 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0330396"" 1:06:25 "" Time passed during each call, %: [25.5531,17.555,17.032,23.8461,16.0138]"" 1:06:27 "" Element types: ["STRING"]"" 1:06:29 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0528601"" 1:06:31 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.03646"" 1:06:33 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0355005"" 1:06:36 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0495593"" 1:06:37 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0331799"" 1:06:37 "" Time passed during each call, %: [25.4674,17.566,17.1037,23.8771,15.9857]"" 1:06:38 "" Element types: ["NIL"]"" 1:06:41 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0529602"" 1:06:42 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0364197"" 1:06:44 "" (last output 0) 50 shuffles run; avg. time per one shuffle: 0.0356604"" 1:06:46 "" (last output 0) 50 shuffles run; avg. time per one shuffle: 0.0379797"" 1:06:46 "" (last output 0) 50 shuffles run; avg. time per one shuffle: 0.000799561"" 1:06:46 "" Time passed during each call, %: [32.3284,22.2316,21.7681,23.1839,0.488074]"" 1:06:50 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 1:06:52 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0548193"" 1:06:54 "" (last output 10000) 50 shuffles run; avg. time per one shuffle: 0.0403198"" 1:06:56 "" (last output 8709) 50 shuffles run; avg. time per one shuffle: 0.0367407"" 1:06:59 "" (last output 8709) 50 shuffles run; avg. time per one shuffle: 0.0521594"" 1:07:00 "" (last output 8709) 50 shuffles run; avg. time per one shuffle: 0.0287207"" 1:07:00 "" Time passed during each call, %: [25.7658,18.9508,17.2686,24.5156,13.4991]"" 1:07:00 ""Running tests for arrays of size 30103"" 1:08:02 "" Element types: ["ARRAY"]"" 1:08:06 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.227471"" 1:08:10 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.257059"" 1:08:13 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.167294"" 1:08:19 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.370939"" 1:08:23 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.204999"" 1:08:23 "" Time passed during each call, %: [18.5273,20.9372,13.6259,30.2127,16.697]"" 1:08:25 "" Element types: ["BOOL"]"" 1:08:28 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.196591"" 1:08:31 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.146646"" 1:08:33 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.142119"" 1:08:37 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.261001"" 1:08:41 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.179354"" 1:08:41 "" Time passed during each call, %: [21.2368,15.8415,15.3524,28.1947,19.3747]"" 1:08:43 "" Element types: ["CODE"]"" 1:08:46 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.197826"" 1:08:49 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.157998"" 1:08:52 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.143354"" 1:08:56 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.270292"" 1:08:59 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.181177"" 1:08:59 "" Time passed during each call, %: [20.8096,16.6201,15.0796,28.4324,19.0583]"" 1:09:02 "" Element types: ["OBJECT"]"" 1:09:05 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.196885"" 1:09:08 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.147705"" 1:09:10 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.141939"" 1:09:14 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.26141"" 1:09:18 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.180118"" 1:09:18 "" Time passed during each call, %: [21.2147,15.9155,15.2942,28.1674,19.4081]"" 1:09:20 "" Element types: ["SCALAR"]"" 1:09:23 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.197352"" 1:09:26 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.146527"" 1:09:28 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.141472"" 1:09:32 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.260003"" 1:09:36 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.179472"" 1:09:36 "" Time passed during each call, %: [21.3393,15.8438,15.2972,28.1137,19.406]"" 1:09:38 "" Element types: ["SIDE"]"" 1:09:41 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.196232"" 1:09:44 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.146477"" 1:09:46 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.141939"" 1:09:51 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.260764"" 1:09:54 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.180003"" 1:09:54 "" Time passed during each call, %: [21.2047,15.8283,15.3379,28.178,19.4511]"" 1:09:59 "" Element types: ["STRING"]"" 1:10:02 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.197057"" 1:10:04 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.147705"" 1:10:07 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.142944"" 1:10:11 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.261647"" 1:10:14 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.180233"" 1:10:14 "" Time passed during each call, %: [21.1984,15.8893,15.3772,28.1466,19.3885]"" 1:10:17 "" Element types: ["NIL"]"" 1:10:20 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.197172"" 1:10:22 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.146764"" 1:10:25 "" (last output 0) 17 shuffles run; avg. time per one shuffle: 0.143591"" 1:10:27 "" (last output 0) 17 shuffles run; avg. time per one shuffle: 0.151353"" 1:10:28 "" (last output 0) 17 shuffles run; avg. time per one shuffle: 0.00911937"" 1:10:28 "" Time passed during each call, %: [30.4278,22.6488,22.1591,23.3569,1.40731]"" 1:10:38 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 1:10:42 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.202349"" 1:10:44 "" (last output 30103) 17 shuffles run; avg. time per one shuffle: 0.163474"" 1:10:47 "" (last output 26404) 17 shuffles run; avg. time per one shuffle: 0.146176"" 1:10:51 "" (last output 26404) 17 shuffles run; avg. time per one shuffle: 0.260936"" 1:10:54 "" (last output 26404) 17 shuffles run; avg. time per one shuffle: 0.148473"" 1:10:54 "" Time passed during each call, %: [21.9609,17.7417,15.8644,28.3193,16.1137]"" 1:10:54 ""Running tests for arrays of size 100000"" 1:14:20 "" Element types: ["ARRAY"]"" 1:14:26 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.34302"" 1:14:34 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.49258"" 1:14:40 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.13901"" 1:14:56 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 3.27261"" 1:15:05 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.92358"" 1:15:06 "" Time passed during each call, %: [14.6445,16.2753,12.42,35.6851,20.9751]"" 1:15:13 "" Element types: ["BOOL"]"" 1:15:19 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.2406"" 1:15:25 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.06101"" 1:15:30 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.0438"" 1:15:44 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 2.83918"" 1:15:53 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.8386"" 1:15:53 "" Time passed during each call, %: [15.4627,13.2243,13.0098,35.3872,22.916]"" 1:16:02 "" Element types: ["CODE"]"" 1:16:08 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.2418"" 1:16:14 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.10801"" 1:16:19 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.05359"" 1:16:33 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 2.89102"" 1:16:42 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.8354"" 1:16:43 "" Time passed during each call, %: [15.2746,13.629,12.9596,35.5607,22.5762]"" 1:16:51 "" Element types: ["OBJECT"]"" 1:16:57 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.23701"" 1:17:02 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.0646"" 1:17:07 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.04539"" 1:17:22 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 2.8376"" 1:17:31 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.83401"" 1:17:31 "" Time passed during each call, %: [15.4268,13.2766,13.037,35.3877,22.8719]"" 1:17:38 "" Element types: ["SCALAR"]"" 1:17:44 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.2354"" 1:17:50 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.0604"" 1:17:55 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.04541"" 1:18:09 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 2.83499"" 1:18:18 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.82759"" 1:18:18 "" Time passed during each call, %: [15.4352,13.2487,13.0614,35.4206,22.834]"" 1:18:27 "" Element types: ["SIDE"]"" 1:18:33 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.2322"" 1:18:38 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.0634"" 1:18:43 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.04419"" 1:18:57 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 2.83582"" 1:19:07 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.8262"" 1:19:07 "" Time passed during each call, %: [15.399,13.2895,13.0494,35.4397,22.8223]"" 1:19:23 "" Element types: ["STRING"]"" 1:19:29 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.2354"" 1:19:34 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.0646"" 1:19:39 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.04819"" 1:19:54 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 2.8406"" 1:20:03 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.83579"" 1:20:03 "" Time passed during each call, %: [15.3952,13.2667,13.0623,35.3987,22.8771]"" 1:20:10 "" Element types: ["NIL"]"" 1:20:16 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.23599"" 1:20:22 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.06421"" 1:20:27 "" (last output 0) 5 shuffles run; avg. time per one shuffle: 1.05178"" 1:20:32 "" (last output 0) 5 shuffles run; avg. time per one shuffle: 1.08162"" 1:20:33 "" (last output 661) 5 shuffles run; avg. time per one shuffle: 0.215796"" 1:20:33 "" Time passed during each call, %: [26.5838,22.8892,22.6219,23.2636,4.64138]"" 1:21:07 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 1:21:14 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.26179"" 1:21:19 "" (last output 100000) 5 shuffles run; avg. time per one shuffle: 1.13259"" 1:21:25 "" (last output 87396) 5 shuffles run; avg. time per one shuffle: 1.06541"" 1:21:38 "" (last output 87396) 5 shuffles run; avg. time per one shuffle: 2.68281"" 1:21:46 "" (last output 87487) 5 shuffles run; avg. time per one shuffle: 1.50601"" 1:21:46 "" Time passed during each call, %: [16.497,14.8078,13.9294,35.0758,19.6899]"" 1:21:46 ""Running tests for arrays of size 301030"" 1:32:13 "" Element types: ["ARRAY"]"" 1:33:00 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 9.33838"" 1:33:51 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 10.2278"" 1:34:35 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.71602"" 1:36:44 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 25.9442"" 1:38:06 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 16.2852"" 1:38:07 "" Time passed during each call, %: [13.2438,14.5051,12.3611,36.7942,23.0958]"" 1:38:29 "" Element types: ["BOOL"]"" 1:39:14 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 9.00039"" 1:39:56 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.46641"" 1:40:39 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.48398"" 1:42:40 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 24.1954"" 1:44:00 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 16.1552"" 1:44:00 "" Time passed during each call, %: [13.575,12.7696,12.7961,36.4931,24.3663]"" 1:44:27 "" Element types: ["CODE"]"" 1:45:12 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 9.01982"" 1:45:56 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.64141"" 1:46:38 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.56719"" 1:48:40 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 24.2522"" 1:49:59 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 15.9282"" 1:50:00 "" Time passed during each call, %: [13.5823,13.0124,12.9007,36.5195,23.9851]"" 1:50:25 "" Element types: ["OBJECT"]"" 1:51:10 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 9.09819"" 1:51:53 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.55762"" 1:52:35 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.41636"" 1:54:36 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 24.24"" 1:55:57 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 16.0894"" 1:55:57 "" Time passed during each call, %: [13.7018,12.8877,12.6749,36.5052,24.2304]"" 1:56:19 "" Element types: ["SCALAR"]"" 1:57:05 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 9.05176"" 1:57:47 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.45464"" 1:58:30 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.6"" 2:00:30 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 24.1119"" 2:01:50 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 15.9739"" 2:01:50 "" Time passed during each call, %: [13.675,12.7729,12.9925,36.4271,24.1326]"" 2:02:15 "" Element types: ["SIDE"]"" 2:03:00 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 9.02461"" 2:03:43 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.47881"" 2:04:25 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.51416"" 2:06:27 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 24.2862"" 2:07:46 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 15.9422"" 2:07:46 "" Time passed during each call, %: [13.6229,12.799,12.8523,36.6607,24.0651]"" 2:08:35 "" Element types: ["STRING"]"" 2:09:21 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 9.05723"" 2:10:03 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.51992"" 2:10:46 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.51846"" 2:12:46 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 24.1034"" 2:14:06 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 15.8607"" 2:14:06 "" Time passed during each call, %: [13.7107,12.8973,12.8951,36.4873,24.0097]"" 2:14:28 "" Element types: ["NIL"]"" 2:15:13 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 9.07227"" 2:15:56 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.59316"" 2:16:38 "" (last output 0) 5 shuffles run; avg. time per one shuffle: 8.37959"" 2:17:21 "" (last output 0) 5 shuffles run; avg. time per one shuffle: 8.54424"" 2:17:30 "" (last output 2035) 5 shuffles run; avg. time per one shuffle: 1.70557"" 2:17:30 "" Time passed during each call, %: [24.996,23.676,23.0876,23.5412,4.6992]"" 2:19:14 "" Element types: ["ARRAY","BOOL","CODE","OBJECT","SCALAR","SIDE","STRING","NIL"]"" 2:19:59 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 9.06416"" 2:20:43 "" (last output 301030) 5 shuffles run; avg. time per one shuffle: 8.76143"" 2:21:25 "" (last output 263362) 5 shuffles run; avg. time per one shuffle: 8.43398"" 2:23:17 "" (last output 263362) 5 shuffles run; avg. time per one shuffle: 22.4017"" 2:24:22 "" (last output 263643) 5 shuffles run; avg. time per one shuffle: 12.956"" 2:24:22 "" Time passed during each call, %: [14.7104,14.2191,13.6877,36.3562,21.0265]"" Plot for "BOOL" (mostly the same for other types) Conclusions (Fixed) 1. No miracles this time. No shuffle in linear time :D (that part was driving me nuts until I finally found the error.) 2. CBA shuffle performs best almost all the time. Unless you need to shuffle array with nils in it, you better stick with CBA_fnc_shuffle. Don't forget to use the [[...]] call CBA_fnc_shuffle; form. Also beware it uses shallow copy of input ([] + _this) to create output array. So if you have some arrays as elements in input array, changes to shuffled array's elements will cause changes to input array as well. 3. On array count somewhere between 10k and 30k BIS's approach (pop in middle (in random actually, averages to middle); push in back) kicks in and shuffle time starts to grow very fast. Especially when using correct shuffling, when random argument decreases and you start to pop from first elements, which leads to shifting almost all array elements. But up until this (10k-30k) point, arrays perform very good and you can pop from wherever you want and shift all array. 4. Array elements definitely do not hold actual data. Copying entire input array does not affect performance too much. Type of array's item does not make too much difference. Therefore my approach to operate on array indexes does not give any advantage vs. operating on input array copy. 5. pushBack has absolutely no advantage over resize+sets on multiple insertions with known final size. On any array size. Compare functions cba_fnc_shuf and cba_fnc_shuf_v. Difference on arrays caused by shallow vs. deep copy; otherwise these two functions show almost same time for all tests. Former uses resize+sets, latter uses pushBack. Sorry for long post, but I felt like I had to do this. Share this post Link to post Share on other sites
Foxyy 16 Posted March 10, 2016 I didn't even know there were BIS functions for shuffling and sorting. I just use a simple in-place Fisher-Yates. private ["_j", "_t"]; for "_i" from count _this - 1 to 1 step -1 do { //Select random index _j = floor random (_i + 1); //Swap if (_i != _j) then { _t = _this select _i; _this set [_i, _this select _j]; _this set [_j, _t]; }; }; _this To preserve the original just pass a copy. +_myArray call my_fnc_shuffle Share this post Link to post Share on other sites
pedeathtrian 99 Posted March 11, 2016 I didn't even know there were BIS functions for shuffling and sorting. I just use a simple in-place Fisher-Yates. I'm glad you've learned something from this topic. NowWhen those functions are fixed you can utilize them and reduce your codebase, increase its readability and maintainability. BTW all (except BIS_fnc_arrayShuffle, which does it wrong for now) shuffle funcs in this topic use the Fisher-Yates. Share this post Link to post Share on other sites
Foxyy 16 Posted March 11, 2016 I'm glad you've learned something from this topic. NowWhen those functions are fixed you can utilize them and reduce your codebase, increase its readability and maintainability. BTW all (except BIS_fnc_arrayShuffle, which does it wrong for now) shuffle funcs in this topic use the Fisher-Yates. I don't have a whole lot of faith in the BIS functions and it seems at least in this case i'm right not to. This way i also get the option of modifying the original array, an option which in my opinion should not be omitted. In addition i like to know exactly what each piece of code does, without having to wade through someone else's potentially undocumented code. Share this post Link to post Share on other sites
