{"id":97,"date":"2015-03-03T22:34:27","date_gmt":"2015-03-03T22:34:27","guid":{"rendered":"https:\/\/blogs.mathworks.com\/developer\/?p=97"},"modified":"2015-03-04T16:58:46","modified_gmt":"2015-03-04T16:58:46","slug":"encouragingly-parallel-part-2","status":"publish","type":"post","link":"https:\/\/blogs.mathworks.com\/developer\/2015\/03\/03\/encouragingly-parallel-part-2\/","title":{"rendered":"Encouragingly Parallel (Part 2)"},"content":{"rendered":"

Last time<\/a> we showed that using a simple parfor loop we could reduce the runtime of a representative test suite from 6 to 7 minutes (when run serially) down to a minute and a half. However, we still faced some problems:<\/p>

  1. A minute and a half is a huge improvement over 6 to 7 minutes, but will still lose my attention.<\/li>
  2. The test output was garbled together without rhyme or reason.<\/li>
  3. The approach was inefficiently using the computational resources available. While the wall-clock time was reduced due to parallelization, there was a significant jump in the overall testing time required because we weren't leveraging the efficiency gains from sharing a fixture across multiple tests.<\/li><\/ol><\/div>

    OK, let's address these issues. First, we'll need to create the same representative suite used in the previous post:<\/p>

    import matlab.unittest.TestSuite<\/span>;\r\nclassSuite = TestSuite.fromFile('aClassBasedTest.m'<\/span>);\r\nfcnSuite = TestSuite.fromFile('aFunctionBasedTest.m'<\/span>);\r\nscriptSuite = TestSuite.fromFile('aScriptBasedTest.m'<\/span>);\r\n\r\nsuite = [repmat(classSuite, 1, 50), repmat(fcnSuite, 1, 50), repmat(scriptSuite, 1, 50)];\r\n<\/pre>
    Add some sophistication<\/b><\/p>
    Rather than using parfor<\/tt><\/b> to run these tests, how might this be done if we take matters a bit more into our own hands using parfeval<\/tt><\/b><\/a>?<\/p>
    First we can get some information from the parallel pool to tell us the number of workers we have at our disposal. We can use this information to split our suite into groups and run a single group per worker to reduce overhead and better utilize our TestClassSetup\/setupOnce fixtures:<\/p>
    p = gcp();\r\nnumWorkers = p.NumWorkers;\r\n\r\nnumGroupsToSchedule = numWorkers; % Run one group\/worker<\/span>\r\n<\/pre>
    Next we need to schedule our groups. We can do this by iterating over our suite and using parfeval<\/tt><\/b> to schedule the suite divided into the number of groups we plan to use. Note, since we need to take the ceiling of the group size, group sizes scheduled later may be smaller than the initial group sizes, which is why the groupLength is calculated for each iteration through the scheduling loop.<\/p>
    % Schedule the groups<\/span>\r\nwhile<\/span> ~isempty(unscheduledSuite)\r\n    groupLength = ceil(numel(unscheduledSuite)\/numGroupsToSchedule);\r\n    groups(numGroupsToSchedule) = ...<\/span>\r\n        parfeval(@run, 1, unscheduledSuite(1:groupLength)');\r\n    % 99 groups of tests on the wall, take one down, pass it around,<\/span>\r\n    % 98 groups of tests on the wall...<\/span>\r\n    numGroupsToSchedule = numGroupsToSchedule - 1;\r\n    unscheduledSuite(1:groupLength) = [];\r\nend<\/span>\r\n% Remove any groups not needed (this happens when the suite size is<\/span>\r\n% smaller than the number of workers)<\/span>\r\ngroups(1:numGroupsToSchedule) = [];\r\ngroups = flip(groups);\r\n<\/pre>
    Once they are scheduled the workers are already off and running, but we can print a little information and fetch the results:<\/p>
    fprintf('Split suite across %d groups on %d workers.\\n'<\/span>, numel(groups), numWorkers);\r\nresults = fetchOutputs(groups);\r\n<\/pre>
    There's a bit of code here so why don't we put it into a function runWithParfeval<\/tt><\/b>. Here it is in its entirety:<\/p>
    function<\/span> results = runWithParfeval(suite)\r\n\r\np = gcp();\r\nnumWorkers = p.NumWorkers;\r\n\r\nnumGroupsToSchedule = numWorkers; % Run one group\/worker<\/span>\r\nunscheduledSuite = suite;\r\n\r\n% Schedule the groups<\/span>\r\nwhile<\/span> ~isempty(unscheduledSuite)\r\n    groupLength = ceil(numel(unscheduledSuite)\/numGroupsToSchedule);\r\n    groups(numGroupsToSchedule) = ...<\/span>\r\n        parfeval(@run, 1, unscheduledSuite(1:groupLength)');\r\n    % 99 groups of tests on the wall, take one down, pass it around,<\/span>\r\n    % 98 groups of tests on the wall...<\/span>\r\n    numGroupsToSchedule = numGroupsToSchedule - 1;\r\n    unscheduledSuite(1:groupLength) = [];\r\nend<\/span>\r\n% Remove any groups not needed (this happens when the suite size is<\/span>\r\n% smaller than the number of workers)<\/span>\r\ngroups(1:numGroupsToSchedule) = [];\r\ngroups = flip(groups);\r\n\r\nfprintf('Split suite across %d groups on %d workers.\\n'<\/span>, numel(groups), numWorkers);\r\nresults = fetchOutputs(groups);\r\nend<\/span>\r\n<\/pre>
    Let's run it!<\/p>
    tic;\r\nresults = runWithParfeval_v1(suite)\r\ntoc;\r\n<\/pre>
    Split suite across 16 groups on 16 workers.\r\n\r\nresults = \r\n\r\n  300x1 TestResult array with properties:\r\n\r\n    Name\r\n    Passed\r\n    Failed\r\n    Incomplete\r\n    Duration\r\n\r\nTotals:\r\n   300 Passed, 0 Failed, 0 Incomplete.\r\n   376.1316 seconds testing time.\r\n\r\nElapsed time is 62.155109 seconds.\r\n<\/pre>
    Where did it go?<\/b><\/p>
    Well, the good news is the output is gone and the bad news is the output is gone. Also, it seems we are fairly efficient in the total execution time since the actual testing time is close to that when run serially. What's more, we are a bit faster, running in about a minute's time. Let's see if we can add some more output to gain more insight into what is going on during this run. In order to add some output, let's create a simple local function that takes an index and the diary output from the parallel.FevalFuture<\/tt><\/b> and prints it:<\/p>
    function<\/span> printResult(idx, output)\r\nbar = '*****************'<\/span>;\r\nfprintf('%s\\nFinished Group %d\\n%s\\n%s'<\/span>, bar, idx, bar, output);\r\nend<\/span>\r\n<\/pre>
    Now with this printed output we will be able to see what happened during each group. Using the fetchNext<\/tt><\/b> method on the parallel.FevalFuture<\/tt><\/b> array as each group is completed allows us to print each group's output as it finishes like so:<\/p>
    for<\/span> idx = 1:numel(groups)\r\n    % fetchNext blocks until next results are available.<\/span>\r\n    groupIdx = fetchNext(groups);\r\n    printResult(groupIdx, groups(groupIdx).Diary);\r\nend<\/span>\r\nresults = fetchOutputs(groups);\r\n<\/pre>
    tic;\r\nresults = runWithParfeval_v2(suite)\r\ntoc;\r\n<\/pre>
    Split suite across 16 groups on 16 workers.\r\n*****************\r\nFinished Group 16\r\n*****************\r\nRunning aScriptBasedTest\r\n..........\r\n........\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 15\r\n*****************\r\nRunning aScriptBasedTest\r\n..........\r\n........\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 14\r\n*****************\r\nRunning aScriptBasedTest\r\n..........\r\n........\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 13\r\n*****************\r\nRunning aScriptBasedTest\r\n..........\r\n........\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 12\r\n*****************\r\nRunning aScriptBasedTest\r\n..........\r\n.........\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 7\r\n*****************\r\nRunning aFunctionBasedTest\r\n..........\r\n.........\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 11\r\n*****************\r\nRunning aFunctionBasedTest\r\n..........\r\nDone aFunctionBasedTest\r\n__________\r\n\r\nRunning aScriptBasedTest\r\n.........\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 8\r\n*****************\r\nRunning aFunctionBasedTest\r\n..........\r\n.........\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 9\r\n*****************\r\nRunning aFunctionBasedTest\r\n..........\r\n.........\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 10\r\n*****************\r\nRunning aFunctionBasedTest\r\n..........\r\n.........\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 6\r\n*****************\r\nRunning aClassBasedTest\r\n.....\r\nDone aClassBasedTest\r\n__________\r\n\r\nRunning aFunctionBasedTest\r\n..........\r\n....\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 1\r\n*****************\r\nRunning aClassBasedTest\r\n..........\r\n.........\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 4\r\n*****************\r\nRunning aClassBasedTest\r\n..........\r\n.........\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 2\r\n*****************\r\nRunning aClassBasedTest\r\n..........\r\n.........\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 3\r\n*****************\r\nRunning aClassBasedTest\r\n..........\r\n.........\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 5\r\n*****************\r\nRunning aClassBasedTest\r\n..........\r\n.........\r\nDone aClassBasedTest\r\n__________\r\n\r\n\r\nresults = \r\n\r\n  300x1 TestResult array with properties:\r\n\r\n    Name\r\n    Passed\r\n    Failed\r\n    Incomplete\r\n    Duration\r\n\r\nTotals:\r\n   300 Passed, 0 Failed, 0 Incomplete.\r\n   407.0311 seconds testing time.\r\n\r\nElapsed time is 60.451688 seconds.\r\n<\/pre>
    The Long Pole<\/b> With this output you can observe that the first groups didn't finish very quickly at all. Doesn't it seem odd that the first groups scheduled were the last groups to finish? This occurs because the first groups are the long pole in our test execution. When we split our test suite into one group per worker one aspect we failed to consider is that these tests take differing amounts of time to execute. In our case, the class-based test has a test method which takes an order of magnitude longer to execute (remember aClassBasedTest\/testLongRunningEndToEndWorkflow<\/tt><\/b>?). Furthermore we loaded these tests on the front of our test suite and executed them all serially on some of the workers. These tests have now become our bottleneck. Let's tweak our approach a bit to be robust to such \"long poles\". If instead of scheduling one group per worker, why don't we try to strike a balance between communication overhead, shared test fixtures, and varying test times by scheduling each worker to execute 3 groups instead of one. Let's change just one line as follows and try it out:<\/p>
    numGroups = numWorkers*3; % Run three groups\/worker<\/span>\r\n<\/pre>
    tic;\r\nresults = runWithParfeval_final(suite)\r\ntoc;\r\n<\/pre>
    Split suite across 48 groups on 16 workers.\r\n*****************\r\nFinished Group 16\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 6\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 12\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 17\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 18\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 8\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 7\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 13\r\n*****************\r\nRunning aClassBasedTest\r\n......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 2\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 14\r\n*****************\r\nRunning aClassBasedTest\r\n......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 9\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 22\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 10\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 19\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 21\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 15\r\n*****************\r\nRunning aClassBasedTest\r\n....\r\nDone aClassBasedTest\r\n__________\r\n\r\nRunning aFunctionBasedTest\r\n..\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 27\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 25\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 20\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 11\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 1\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 32\r\n*****************\r\nRunning aFunctionBasedTest\r\n..\r\nDone aFunctionBasedTest\r\n__________\r\n\r\nRunning aScriptBasedTest\r\n....\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 30\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 26\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 24\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 5\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 33\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 34\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 37\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 36\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 35\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 38\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 3\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 4\r\n*****************\r\nRunning aClassBasedTest\r\n.......\r\nDone aClassBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 23\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 44\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 39\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 41\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 46\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 40\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 42\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 29\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 31\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 28\r\n*****************\r\nRunning aFunctionBasedTest\r\n......\r\nDone aFunctionBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 48\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 43\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 47\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n*****************\r\nFinished Group 45\r\n*****************\r\nRunning aScriptBasedTest\r\n......\r\nDone aScriptBasedTest\r\n__________\r\n\r\n\r\nresults = \r\n\r\n  300x1 TestResult array with properties:\r\n\r\n    Name\r\n    Passed\r\n    Failed\r\n    Incomplete\r\n    Duration\r\n\r\nTotals:\r\n   300 Passed, 0 Failed, 0 Incomplete.\r\n   441.8035 seconds testing time.\r\n\r\nElapsed time is 31.292908 seconds.\r\n<\/pre>
    Beautiful! We get an order of magnitude speed up from the serial case, it executes in a third the wall-clock time as parfor<\/tt><\/b> and half the time as parfeval<\/tt><\/b> with one group per worker. Add to the mix the rational test output and we are gold! Here is the finished function:<\/p>
    function<\/span> results = runWithParfeval(suite)\r\n\r\np = gcp();\r\nnumWorkers = p.NumWorkers;\r\n\r\nnumGroupsToSchedule = numWorkers*3; % Run three groups\/worker<\/span>\r\nunscheduledSuite = suite;\r\n\r\n% Schedule the groups<\/span>\r\nwhile<\/span> ~isempty(unscheduledSuite)\r\n    groupLength = ceil(numel(unscheduledSuite)\/numGroupsToSchedule);\r\n    groups(numGroupsToSchedule) = ...<\/span>\r\n        parfeval(@run, 1, unscheduledSuite(1:groupLength)');\r\n    % 99 groups of tests on the wall, take one down, pass it around,<\/span>\r\n    % 98 groups of tests on the wall...<\/span>\r\n    numGroupsToSchedule = numGroupsToSchedule - 1;\r\n    unscheduledSuite(1:groupLength) = [];\r\nend<\/span>\r\n% Remove any groups not needed (this happens when the suite size is<\/span>\r\n% smaller than the number of workers)<\/span>\r\ngroups(1:numGroupsToSchedule) = [];\r\ngroups = flip(groups);\r\n\r\nfprintf('Split suite across %d groups on %d workers.\\n'<\/span>, numel(groups), numWorkers);\r\n\r\nfor<\/span> idx = 1:numel(groups)\r\n    % fetchNext blocks until next results are available.<\/span>\r\n    groupIdx = fetchNext(groups);\r\n    printResult(groupIdx, groups(groupIdx).Diary);\r\nend<\/span>\r\nresults = fetchOutputs(groups);\r\nend<\/span>\r\n\r\nfunction<\/span> printResult(idx, output)\r\nbar = '*****************'<\/span>;\r\nfprintf('%s\\nFinished Group %d\\n%s\\n%s'<\/span>, bar, idx, bar, output);\r\nend<\/span>\r\n<\/pre>
    Conclusion<\/b><\/p>
    As demonstrated we can leverage parallelism in our day to day testing workflows to significantly speed up the wall clock time of our code execution. This can be done trivially using parfor<\/tt><\/b>, but the power of parfeval<\/tt><\/b> can be utilized to further improve the execution time, better utilize shared fixtures on the workers, and control test output, among many other benefits not shown here.<\/p>
    Have you used any other methods for running tests in parallel? If so share your experiences in the comments!<\/p>