Skip to content

Profiler

Christopher Ross-Gill edited this page Aug 1, 2016 · 1 revision

Table of Contents

Overview

V 2.200.12 includes a way to profile your code.

Although it's just a starting point (more is needed), it can provide useful information.

Statistics information is returned from the STATS function.

>> ? stats
USAGE:
        STATS /show /profile /timer /evals

DESCRIPTION:
        Provides status and statistic information about the interpreter.
        STATS is a native value.

REFINEMENTS:
        /show -- Print formatted results to console
        /profile -- Returns profiler object
        /timer -- Returns high resolution timer (nanoseconds)
        /evals -- Returns number of values evaluated

NOTE: The timer only works on hardware that provides a high performance timer.

Profile Examples

Here is an example that shows profile information as of the first prompt after boot:

>> stats/profile
== make object! [
    timer: 1558343515056	; timer in nanoseconds (since OS boot)
    evals: 16513		; number of values evaluated
    eval-natives: 1832		; series allocated
    eval-functions: 284		; series deallocated
    series-made: 5626		; series expanded
    series-freed: 1427		; bytes requested by series
    series-expanded: 30		; series reclaimed by recycle
    series-bytes: 819454	; natives evaluated
    series-recycled: 1396	; functions evaluated (non-native)
    made-blocks: 3793		; blocks created
    made-objects: 69		; objects created
    recycles: 1                 ; garbage collections
]

So, this is what the boot required. Note that the time is not the startup time, it is your computer's high-performance timer value.

Now, call the HELP function and then check STATS again:

>> help
To use HELP, supply a word or value as

        help insert

...

>> stats/profile
== make object! [
    timer: 1558351665864
    evals: 16524
    eval-natives: 1839  <-- 7 natives evaluated
    eval-functions: 285 <-- help function itself
    series-made: 5629
    series-freed: 1427
    series-expanded: 30
    series-bytes: 819566
    series-recycled: 1396  
    made-blocks: 3796   <-- 3 blocks used
    made-objects: 69
    recycles: 1
]

Here, let's try listing the directory:

>> ls
1000cows.r ... (about 55 files)

>> stats/profile
== make object! [
    timer: 1558361784940
    evals: 18248
    eval-natives: 2584  <-- 745 natives evaluated
    eval-functions: 290 <-- 5 functions evaluated
    series-made: 5758
    series-freed: 1433
    series-expanded: 36
    series-bytes: 823812
    series-recycled: 1396
    made-blocks: 3818   <-- 22 blocks used
    made-objects: 70    <-- 1 object used
    recycles: 1
]

DP - Delta Profile Mezzanine

Similar to DT for time, there is a DP function for showing differences in the profile when evaluating a specific block:

>> dp [loop 10 [a: 10]]
== make object! [
    timer: 11
    evals: 31
    eval-natives: 4
    eval-functions: 1
    series-made: 1
    series-freed: 0
    series-expanded: 0
    series-bytes: 432
    series-recycled: 0
    made-blocks: 1
    made-objects: 0
    recycles: 0
]

Let's check the tiger.r SVG for a few hundred frames:

>> dp [do %tiger.r]
== make object! [
    timer: 4989979
    evals: 7085
    eval-natives: 3349
    eval-functions: 214
    series-made: 537
    series-freed: 4
    series-expanded: 4
    series-bytes: 382035
    series-recycled: 0
    made-blocks: 504
    made-objects: 3
    recycles: 0
]

Useful info! It shows that Rebol's graphics system is quite efficient.

Useful Observations

The series-expanded field is a useful measurement of how well a programmer did in determining the sizes required for series.

Note the difference between these two examples:

>> str: ""
>> dp [loop 10000 [append str "a"]]
== make object! [
    timer: 4516
    evals: 30011
    eval-natives: 10004
    eval-functions: 1
    series-made: 9
    series-freed: 8
    series-expanded: 8
    series-bytes: 22784
    series-recycled: 0
    made-blocks: 1
    made-objects: 0
    recycles: 0
]
>> str: make string! 15000
>> dp [loop 10000 [append str "a"]]
== make object! [
    timer: 4351
    evals: 30011
    eval-natives: 10004
    eval-functions: 1
    series-made: 1
    series-freed: 0
    series-expanded: 0
    series-bytes: 432
    series-recycled: 0
    made-blocks: 1
    made-objects: 0
    recycles: 0

Notice that the second method did not require any series expansions.

Clone this wiki locally