{"id":167,"date":"2009-01-06T16:36:10","date_gmt":"2009-01-06T16:36:10","guid":{"rendered":"https:\/\/blogs.mathworks.com\/loren\/2009\/01\/06\/nested-timing\/"},"modified":"2009-01-07T02:25:45","modified_gmt":"2009-01-07T02:25:45","slug":"nested-timing","status":"publish","type":"post","link":"https:\/\/blogs.mathworks.com\/loren\/2009\/01\/06\/nested-timing\/","title":{"rendered":"Nested Timing"},"content":{"rendered":"<div xmlns:mwsh=\"https:\/\/www.mathworks.com\/namespace\/mcode\/v1\/syntaxhighlight.dtd\" class=\"content\">\r\n   <introduction>\r\n      <p>Did you know that you can use <a href=\"https:\/\/www.mathworks.com\/help\/releases\/R2008b\/techdoc\/ref\/tic.html\"><tt>tic<\/tt> and <tt>toc<\/tt><\/a> to measure times of operations that may have other timed operations nested inside?\r\n      <\/p>\r\n   <\/introduction>\r\n   <h3>Contents<\/h3>\r\n   <div>\r\n      <ul>\r\n         <li><a href=\"#1\">Example<\/a><\/li>\r\n         <li><a href=\"#2\">Compare Times<\/a><\/li>\r\n         <li><a href=\"#5\">Timing Tips<\/a><\/li>\r\n         <li><a href=\"#6\">What are Your Timing Patterns?<\/a><\/li>\r\n      <\/ul>\r\n   <\/div>\r\n   <h3>Example<a name=\"1\"><\/a><\/h3>\r\n   <p>Suppose I want to see how long some operations take, and the overall calculation as well.  Let's see how long it takes to\r\n      create some magic squares and how long it takes to find the <a href=\"https:\/\/www.mathworks.com\/help\/releases\/R2008b\/techdoc\/ref\/rank.html\"><tt>rank<\/tt><\/a> for each one.\r\n   <\/p><pre style=\"background: #F9F7F3; padding: 10px; border: 1px solid rgb(200,200,200)\">Nsizes = [10 20 50 100 200 500 1000];\r\nN = numel(Nsizes);\r\nmagTimes = zeros(1,N);\r\nrankTimes = zeros(1,N);\r\nranks = zeros(1,N);\r\ntimeTemp = tic;\r\n<span style=\"color: #0000FF\">for<\/span> k = 1:N\r\n    mTemp = tic;\r\n    m = magic(Nsizes(k));\r\n    magTimes(k) = toc(mTemp);\r\n    rTemp = tic;\r\n    ranks(k) = rank(m);\r\n    rankTimes(k) = toc(rTemp);\r\n<span style=\"color: #0000FF\">end<\/span>\r\nallTimes = toc(timeTemp);<\/pre><h3>Compare Times<a name=\"2\"><\/a><\/h3>\r\n   <p>If I sum the times for creating the magic squares and computing their ranks, I should get the same time as the overall time\r\n      calculation, right?\r\n   <\/p><pre style=\"background: #F9F7F3; padding: 10px; border: 1px solid rgb(200,200,200)\">totTimes = sum(magTimes)+sum(rankTimes)<\/pre><pre style=\"font-style:oblique\">totTimes =\r\n        4.0211\r\n<\/pre><pre style=\"background: #F9F7F3; padding: 10px; border: 1px solid rgb(200,200,200)\">allTimes<\/pre><pre style=\"font-style:oblique\">allTimes =\r\n       4.0344\r\n<\/pre><p>The totals don't match!  That's because there's other stuff going on in the loop, including overhead for managing the loop.<\/p>\r\n   <h3>Timing Tips<a name=\"5\"><\/a><\/h3>\r\n   <p>To get relative time estimates, you can use the <a href=\"https:\/\/www.mathworks.com\/help\/releases\/R2008b\/techdoc\/ref\/profile.html\"><tt>profiler<\/tt><\/a>, <tt>tic\/toc<\/tt>, or <a href=\"https:\/\/blogs.mathworks.com\/steve\/\">Steve's<\/a> <a href=\"https:\/\/blogs.mathworks.com\/pick\/2008\/03\/28\/timeit-benchmarking-function\/\"><tt>timeit<\/tt><\/a> function on the file exchange.  Though I am not doing so in this post, you generally should time functionality written in\r\n      functions, especially if getting the best performance is your goal.\r\n   <\/p>\r\n   <h3>What are Your Timing Patterns?<a name=\"6\"><\/a><\/h3>\r\n   <p>Do you find yourself timing nested calculations?  Do you have other strategies? Please post them <a href=\"https:\/\/blogs.mathworks.com\/loren\/?p=167\">here<\/a>.\r\n   <\/p><script language=\"JavaScript\">\r\n<!--\r\n\r\n    function grabCode_679c2902257f4188a1a1fc78557d6330() {\r\n        \/\/ Remember the title so we can use it in the new page\r\n        title = document.title;\r\n\r\n        \/\/ Break up these strings so that their presence\r\n        \/\/ in the Javascript doesn't mess up the search for\r\n        \/\/ the MATLAB code.\r\n        t1='679c2902257f4188a1a1fc78557d6330 ' + '##### ' + 'SOURCE BEGIN' + ' #####';\r\n        t2='##### ' + 'SOURCE END' + ' #####' + ' 679c2902257f4188a1a1fc78557d6330';\r\n    \r\n        b=document.getElementsByTagName('body')[0];\r\n        i1=b.innerHTML.indexOf(t1)+t1.length;\r\n        i2=b.innerHTML.indexOf(t2);\r\n \r\n        code_string = b.innerHTML.substring(i1, i2);\r\n        code_string = code_string.replace(\/REPLACE_WITH_DASH_DASH\/g,'--');\r\n\r\n        \/\/ Use \/x3C\/g instead of the less-than character to avoid errors \r\n        \/\/ in the XML parser.\r\n        \/\/ Use '\\x26#60;' instead of '<' so that the XML parser\r\n        \/\/ doesn't go ahead and substitute the less-than character. \r\n        code_string = code_string.replace(\/\\x3C\/g, '\\x26#60;');\r\n\r\n        author = 'Loren Shure';\r\n        copyright = 'Copyright 2008 The MathWorks, Inc.';\r\n\r\n        w = window.open();\r\n        d = w.document;\r\n        d.write('<pre>\\n');\r\n        d.write(code_string);\r\n\r\n        \/\/ Add author and copyright lines at the bottom if specified.\r\n        if ((author.length > 0) || (copyright.length > 0)) {\r\n            d.writeln('');\r\n            d.writeln('%%');\r\n            if (author.length > 0) {\r\n                d.writeln('% _' + author + '_');\r\n            }\r\n            if (copyright.length > 0) {\r\n                d.writeln('% _' + copyright + '_');\r\n            }\r\n        }\r\n\r\n        d.write('<\/pre>\\n');\r\n      \r\n      d.title = title + ' (MATLAB code)';\r\n      d.close();\r\n      }   \r\n      \r\n-->\r\n<\/script><p style=\"text-align: right; font-size: xx-small; font-weight:lighter;   font-style: italic; color: gray\"><br><a href=\"javascript:grabCode_679c2902257f4188a1a1fc78557d6330()\"><span style=\"font-size: x-small;        font-style: italic;\">Get \r\n            the MATLAB code \r\n            <noscript>(requires JavaScript)<\/noscript><\/span><\/a><br><br>\r\n      Published with MATLAB&reg; 7.7<br><\/p>\r\n<\/div>\r\n<!--\r\n679c2902257f4188a1a1fc78557d6330 ##### SOURCE BEGIN #####\r\n%% Nested Timing\r\n% Did you know that you can use\r\n% <https:\/\/www.mathworks.com\/help\/releases\/R2008b\/techdoc\/ref\/tic.html |tic| and |toc|> \r\n% to measure times of operations that may have other timed operations\r\n% nested inside?  \r\n%% Example\r\n% Suppose I want to see how long some operations take, and\r\n% the overall calculation as well.  Let's see how long it takes to create\r\n% some magic squares and how long it takes to find the\r\n% <https:\/\/www.mathworks.com\/help\/releases\/R2008b\/techdoc\/ref\/rank.html |rank|>\r\n% for each one.\r\nNsizes = [10 20 50 100 200 500 1000];\r\nN = numel(Nsizes);\r\nmagTimes = zeros(1,N);\r\nrankTimes = zeros(1,N);\r\nranks = zeros(1,N);\r\ntimeTemp = tic;\r\nfor k = 1:N\r\n    mTemp = tic;\r\n    m = magic(Nsizes(k));\r\n    magTimes(k) = toc(mTemp);\r\n    rTemp = tic;\r\n    ranks(k) = rank(m);\r\n    rankTimes(k) = toc(rTemp);\r\nend\r\nallTimes = toc(timeTemp);\r\n%% Compare Times\r\n% If I sum the times for creating the magic squares and computing their\r\n% ranks, I should get the same time as the overall time calculation, right?\r\ntotTimes = sum(magTimes)+sum(rankTimes)\r\n%%\r\nallTimes\r\n%%\r\n% The totals don't match!  That's because there's other stuff going on in\r\n% the loop, including overhead for managing the loop.\r\n%% Timing Tips\r\n% To get relative time estimates, you can use the\r\n% <https:\/\/www.mathworks.com\/help\/releases\/R2008b\/techdoc\/ref\/profile.html |profiler|>,\r\n% |tic\/toc|, or <https:\/\/blogs.mathworks.com\/steve\/ Steve's>\r\n% <https:\/\/blogs.mathworks.com\/pick\/2008\/03\/28\/timeit-benchmarking-function\/ |timeit|>\r\n% function on the file exchange.  Though I am not doing so in this post,\r\n% you generally should time functionality written in functions, especially\r\n% if getting the best performance is your goal.\r\n%% What are Your Timing Patterns?\r\n% Do you find yourself timing nested calculations?  Do you have other\r\n% strategies?  \r\n% Please post them <https:\/\/blogs.mathworks.com\/loren\/?p=167 here>.\r\n\r\n\r\n##### SOURCE END ##### 679c2902257f4188a1a1fc78557d6330\r\n-->","protected":false},"excerpt":{"rendered":"<p>\r\n   \r\n      Did you know that you can use tic and toc to measure times of operations that may have other timed operations nested inside?\r\n      \r\n   \r\n   Contents\r\n   \r\n  ... <a class=\"read-more\" href=\"https:\/\/blogs.mathworks.com\/loren\/2009\/01\/06\/nested-timing\/\">read more >><\/a><\/p>","protected":false},"author":39,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":[],"categories":[16,15],"tags":[],"_links":{"self":[{"href":"https:\/\/blogs.mathworks.com\/loren\/wp-json\/wp\/v2\/posts\/167"}],"collection":[{"href":"https:\/\/blogs.mathworks.com\/loren\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/blogs.mathworks.com\/loren\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/blogs.mathworks.com\/loren\/wp-json\/wp\/v2\/users\/39"}],"replies":[{"embeddable":true,"href":"https:\/\/blogs.mathworks.com\/loren\/wp-json\/wp\/v2\/comments?post=167"}],"version-history":[{"count":0,"href":"https:\/\/blogs.mathworks.com\/loren\/wp-json\/wp\/v2\/posts\/167\/revisions"}],"wp:attachment":[{"href":"https:\/\/blogs.mathworks.com\/loren\/wp-json\/wp\/v2\/media?parent=167"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/blogs.mathworks.com\/loren\/wp-json\/wp\/v2\/categories?post=167"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/blogs.mathworks.com\/loren\/wp-json\/wp\/v2\/tags?post=167"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}