title: Measure performance for small application
body: <p>I wrote a statusbar for Sway WM (<a href="https://swaywm.org" rel="nofollow noreferrer">https://swaywm.org</a>), basically print every second some information (loadavg, cpu usage, memory usage, time, ...).</p>
  <p>The project (<a href="https://gitlab.com/Yellowhat/statusbar" rel="nofollow noreferrer">https://gitlab.com/Yellowhat/statusbar</a>) is purely to learn about CI/CD and how to measure performance (if possible in a noisy environment).</p>
  <p>Initially the project was all written in <code>python</code> but some time ago I decided to write a functionally equivalent in <code>rust</code> (<a href="https://gitlab.com/Yellowhat/statusbar/-/tree/master/tools/rust" rel="nofollow noreferrer">https://gitlab.com/Yellowhat/statusbar/-/tree/master/tools/rust</a>) (they print out exactly the same information).</p>
  <p>Looking at the number of instructions run (<code>I refs</code> using <code>cachegrind</code>, slimmed version) per second of execution:</p>
  <ul>
  <li><code>python</code>: ~800k</li>
  <li><code>rust</code>: ~35k</li>
  </ul>
  <p>I could conclude that the <code>rust</code> version is much &quot;lighter&quot; than the <code>python</code> one.</p>
  <p>As the statusbar will run continuosly while the system is running, I want to understand the impact that it has on my system. So I decided to monitor my system using the following <code>python</code> script while idling (do not touch the computer for 1 hour, 100% brightness):</p>
  <pre class="lang-py prettyprint-override"><code>from time import sleep
  
  while True:
      stat = open(&quot;/proc/stat&quot;).readlines()[0].split()[1:8]
      power = float(open(&quot;/sys/class/power_supply/BAT0/power_now&quot;).read().strip()) / 10**6
      print(f&quot;{stat},{power}&quot;)
      sleep(1)
  </code></pre>
  <ul>
  <li><code>/proc/stat</code> returns how much CPU time (jiffies) is spent in:
  <ul>
  <li><code>user</code>: normal processes executing in user mode</li>
  <li><code>nice</code>: niced processes executing in user mode</li>
  <li><code>system</code>: processes executing in kernel mode</li>
  <li><code>idle</code>: twiddling thumbs</li>
  <li><code>iowait</code>: waiting for I/O to complete</li>
  <li><code>irq</code>: servicing interrupts</li>
  <li><code>softirq</code>: servicing softirqs</li>
  </ul>
  </li>
  <li><code>/sys/class/power_supply/BAT0/power_now</code> returns how much power (micro Watt) is taken from the battery</li>
  </ul>
  <p>I have compared 4 cases:</p>
  <ol>
  <li><strong>tty</strong>: boot the computer and run the script from <code>tty</code></li>
  <li><strong>sway</strong>: boot the computer, start <code>sway</code> (without a bar), open the terminal and run the script</li>
  <li><strong>sway barpy</strong>: boot the computer, start <code>sway</code> (with the <code>python</code> version), open the terminal and run the script</li>
  <li><strong>sway barrs</strong>: boot the computer, start <code>sway</code> (with the <code>rust</code> version), open the terminal and run the script</li>
  </ol>
  <p>The following graph shows the <code>SUM(user_t, nice_t, system_t, iowait_t, irq_t, softirq_t) - SUM(user_t0, nice_t0, system_t0, iowait_t0, irq_t0, softirq_t0)</code>, (how much time was spent by all CPUs not idling) - (the initial value at the beginning of the test), versus time for the 4 cases:</p>
  <p><a href="https://i.stack.imgur.com/ViQp8.png" rel="nofollow noreferrer"><img src="https://i.stack.imgur.com/ViQp8.png" alt="CPU Time" /></a></p>
  <p>As you can see, <strong>tty</strong> is the lowest, followed by <strong>sway</strong>, but interestingly the <code>rust</code> version is much higher than the <code>python</code> one.</p>
  <p>The following graph shows the power versus time for the 4 cases:</p>
  <p><a href="https://i.stack.imgur.com/8TRYP.png" rel="nofollow noreferrer"><img src="https://i.stack.imgur.com/8TRYP.png" alt="Power" /></a></p>
  <p>As you can see, <strong>tty</strong> has the lowest consumption, followed by <strong>sway</strong>, very close by <code>rust</code> and <code>python</code> at last. This is the kind of result I would expect.</p>
  <p>The first graph would suggest that, in this instance, <code>rust</code> is not lighter than <code>python</code>.</p>
  <p>Are there more reliable way to measure &quot;light&quot; applications?
  Am I misunderstanding the <code>/proc/stat</code> content?</p>
  <p>Thanks</p>
  <h1>Update 1</h1>
  <p>The following graph shows the <code>user_t - user_t0</code>, <code>nice_t - nice_t0</code>, <code>system_t - system_t0</code> versus time for <code>python</code> and <code>rust</code>:</p>
  <p><a href="https://i.stack.imgur.com/aYuKa.png" rel="nofollow noreferrer"><img src="https://i.stack.imgur.com/aYuKa.png" alt="User, Nice, System" /></a></p>
  <p><code>user</code> are similar instead <code>system</code> and <code>nice</code> are much higher for <code>rust</code>.</p>
  <h1>Update 2</h1>
  <p>As suggested by Peter Cordes I have run:</p>
  <pre><code>perf stat -a -d -e cpu-cycles,cycles,cycles:u,instructions,instructions:u -r 10 &lt;binary&gt;
  </code></pre>
  <p>The following tables summarise the results:</p>
  <div class="s-table-container">
  <table class="s-table">
  <thead>
  <tr>
  <th>Version</th>
  <th>Duration</th>
  <th>cpu-cycles</th>
  <th>cycles</th>
  <th>cycles:u</th>
  <th>instructions</th>
  <th>instructions:u</th>
  </tr>
  </thead>
  <tbody>
  <tr>
  <td>python</td>
  <td>0</td>
  <td>285,248,768</td>
  <td>285,492,709</td>
  <td>215,681,759</td>
  <td>323,852,866</td>
  <td>278,792,657</td>
  </tr>
  <tr>
  <td>python</td>
  <td>60</td>
  <td>3,038,749,610</td>
  <td>3,046,770,477</td>
  <td>1,360,477,472</td>
  <td>2,425,399,588</td>
  <td>1,612,134,730</td>
  </tr>
  <tr>
  <td>python</td>
  <td>120</td>
  <td>5,802,965,874</td>
  <td>5,818,929,489</td>
  <td>2,496,192,062</td>
  <td>4,536,305,443</td>
  <td>2,890,941,664</td>
  </tr>
  <tr>
  <td>rust</td>
  <td>0</td>
  <td>1,165,223</td>
  <td>1,165,869</td>
  <td>304,188</td>
  <td>1,319,168</td>
  <td>442,565</td>
  </tr>
  <tr>
  <td>rust</td>
  <td>60</td>
  <td>3,791,712,516</td>
  <td>3,799,515,523</td>
  <td>1,654,232,537</td>
  <td>3,355,917,423</td>
  <td>2,073,096,815</td>
  </tr>
  <tr>
  <td>rust</td>
  <td>120</td>
  <td>7,878,549,570</td>
  <td>7,897,534,278</td>
  <td>3,341,698,282</td>
  <td>6,665,643,064</td>
  <td>4,144,148,632</td>
  </tr>
  </tbody>
  </table>
  </div>
  <p>Removing the initial value (duration = 0) and dividing by the duration:</p>
  <div class="s-table-container">
  <table class="s-table">
  <thead>
  <tr>
  <th>Version</th>
  <th>Duration</th>
  <th>cpu-cycles</th>
  <th>cycles</th>
  <th>cycles:u</th>
  <th>instructions</th>
  <th>instructions:u</th>
  </tr>
  </thead>
  <tbody>
  <tr>
  <td>python</td>
  <td>60</td>
  <td>45,891,681</td>
  <td>46,021,296</td>
  <td>19,079,929</td>
  <td>35,025,779</td>
  <td>22,222,368</td>
  </tr>
  <tr>
  <td>python</td>
  <td>120</td>
  <td>45,980,976</td>
  <td>46,111,973</td>
  <td>19,004,253</td>
  <td>35,103,771</td>
  <td>21,767,908</td>
  </tr>
  <tr>
  <td>rust</td>
  <td>60</td>
  <td>63,175,788</td>
  <td>63,305,828</td>
  <td>27,565,472</td>
  <td>55,909,971</td>
  <td>34,544,238</td>
  </tr>
  <tr>
  <td>rust</td>
  <td>120</td>
  <td>65,644,870</td>
  <td>65,803,070</td>
  <td>27,844,951</td>
  <td>55,536,032</td>
  <td>34,530,884</td>
  </tr>
  </tbody>
  </table>
  </div>
  <p>Again, seems that <code>rust</code> version is running more cycles/instructions than the <code>python</code> one.</p>
  <h1>Update 3</h1>
  <pre class="lang-sh prettyprint-override"><code>$ valgrind \
      --tool=cachegrind \
      --cachegrind-out-file=/dev/null \
      --trace-children=yes \
      --I1=32768,8,64 \
      --D1=32768,8,64 \
      --LL=8388608,16,64 \
      --cache-sim=yes \
      --branch-sim=yes \
      &lt;binary&gt;
  </code></pre>
  <p>Run for 120 seconds:</p>
  <ul>
  <li><code>python</code> version:</li>
  </ul>
  <pre class="lang-sh prettyprint-override"><code>I   refs:      328,117,776
  I1  misses:      5,268,249
  LLi misses:         15,274
  I1  miss rate:        1.61%
  LLi miss rate:        0.00%
  
  D   refs:      135,851,173  (95,116,936 rd   + 40,734,237 wr)
  D1  misses:      4,717,331  ( 4,145,263 rd   +    572,068 wr)
  LLd misses:        167,298  (    57,266 rd   +    110,032 wr)
  D1  miss rate:         3.5% (       4.4%     +        1.4%  )
  LLd miss rate:         0.1% (       0.1%     +        0.3%  )
  
  LL refs:         9,985,580  ( 9,413,512 rd   +    572,068 wr)
  LL misses:         182,572  (    72,540 rd   +    110,032 wr)
  LL miss rate:          0.0% (       0.0%     +        0.3%  )
  
  Branches:       60,115,083  (56,103,351 cond +  4,011,732 ind)
  Mispredicts:     5,661,255  ( 4,245,148 cond +  1,416,107 ind)
  Mispred rate:          9.4% (       7.6%     +       35.3%   )
  </code></pre>
  <ul>
  <li><code>rust</code> version:</li>
  </ul>
  <pre class="lang-sh prettyprint-override"><code>I   refs:      100,950,027
  I1  misses:        351,835
  LLi misses:          5,859
  I1  miss rate:        0.35%
  LLi miss rate:        0.01%
  
  D   refs:       44,227,512  (24,903,985 rd   + 19,323,527 wr)
  D1  misses:        670,307  (   341,521 rd   +    328,786 wr)
  LLd misses:         34,962  (    20,657 rd   +     14,305 wr)
  D1  miss rate:         1.5% (       1.4%     +        1.7%  )
  LLd miss rate:         0.1% (       0.1%     +        0.1%  )
  
  LL refs:         1,022,142  (   693,356 rd   +    328,786 wr)
  LL misses:          40,821  (    26,516 rd   +     14,305 wr)
  LL miss rate:          0.0% (       0.0%     +        0.1%  )
  
  Branches:       19,868,173  (18,608,630 cond +  1,259,543 ind)
  Mispredicts:     1,289,209  (   771,555 cond +    517,654 ind)
  Mispred rate:          6.5% (       4.1%     +       41.1%   )
  </code></pre>