Loop time execution in Javascript

Question

Lets consider the following snippet as example:

var len = 1000000,
    testArr = []

    for (var i = 0; i < len; i++) {
        testArr.push(i+1)
    }

    function mprofile(name, subject, object) {
        var start = new Date().getTime(),
            result = subject(object),
            end = new Date().getTime() - start
        console.log(name)
        console.log('Result: ' + result)
        console.log(end)
    }

    var length = testArr.length,
        start = new Date().getTime(),
        cnt = 0

    for (i = 0; i < length; i++) {
        cnt += testArr[i]
    }

    console.log('Regular loop:')
    console.log('Result: ' + cnt)
    console.log(new Date().getTime() - start);

    start = new Date().getTime()
    cnt = i = 0
    for (i = length; i--; ) {
        cnt += testArr[i]
    }

    console.log('Reversered loop')
    console.log('Result: ' + cnt)
    console.log(new Date().getTime() - start);

    start = new Date().getTime()
    cnt = i = 0
    var startAt = length%8,
        iterations = Math.floor((length+7) / 8)

    do {
        switch (startAt) {
            case 0: cnt += testArr[i++]
            case 7: cnt += testArr[i++]
            case 6: cnt += testArr[i++]
            case 5: cnt += testArr[i++]
            case 4: cnt += testArr[i++]
            case 3: cnt += testArr[i++]
            case 2: cnt += testArr[i++]
            case 1: cnt += testArr[i++]
        }
        startAt = 0
    } while(--iterations)

    console.log('Duffs device')
    console.log('Result: ' + cnt)
    console.log(new Date().getTime() - start);

    start = new Date().getTime()
    cnt = i = 0
    iterations = Math.floor((length+7) / 8)

    switch (length % 8) {
        case 0: cnt += testArr[i++]
        case 7: cnt += testArr[i++]
        case 6: cnt += testArr[i++]
        case 5: cnt += testArr[i++]
        case 4: cnt += testArr[i++]
        case 3: cnt += testArr[i++]
        case 2: cnt += testArr[i++]
        case 1: cnt += testArr[i++]
    }

    while(--iterations) {
        cnt += testArr[i++]
        cnt += testArr[i++]
        cnt += testArr[i++]
        cnt += testArr[i++]
        cnt += testArr[i++]
        cnt += testArr[i++]
        cnt += testArr[i++]
        cnt += testArr[i++]
    }

    console.log('Optimized Duffs device')
    console.log('Result: ' + cnt)
    console.log(new Date().getTime() - start);


    mprofile(
        'Profiled regular loop',
        function(arr) {
            var cnt = 0,
                length = arr.length
            for (i = 0; i < length; i++) {
                cnt += testArr[i]
            }
            return cnt
        },
        testArr
    )

    mprofile(
        'Profiled reversed loop',
        function(arr) {
            var cnt = 0,
                length = arr.length
            for (i = length; i--; ) {
                cnt += testArr[i]
            }
            return cnt
        },
        testArr
    )

    mprofile(
        'Profiled Duffs device',
        function(arr) {
            var cnt = i = 0,
                length = arr.length,
                startAt = length%8,
                iterations = Math.floor((length+7) / 8)

            do {
                switch (startAt) {
                    case 0: cnt += arr[i++]
                    case 7: cnt += arr[i++]
                    case 6: cnt += arr[i++]
                    case 5: cnt += arr[i++]
                    case 4: cnt += arr[i++]
                    case 3: cnt+ = arr[i++]                     
                       case 2: cnt += arr[i++]
                    case 1: cnt += arr[i++]
                }
                startAt = 0
            } while(--iterations)
            return cnt
        },
        testArr
    )

    mprofile(
        'Profiled optimized Duffs device',
        function(arr) {
            var cnt = i = 0,
                length = arr.length,
                iterations = Math.floor((length+7) / 8)

            switch (length % 8) {
                case 0: cnt += arr[i++]
                case 7: cnt += arr[i++]
                case 6: cnt += arr[i++]
                case 5: cnt += arr[i++]
                case 4: cnt += arr[i++]
                case 3: cnt += arr[i++]
                case 2: cnt += arr[i++]
                case 1: cnt += arr[i++]
            }

            while(--iterations) {
                cnt += arr[i++]
                cnt += arr[i++]
                cnt += arr[i++]
                cnt += arr[i++]
                cnt += arr[i++]
                cnt += arr[i++]
                cnt += arr[i++]
                cnt += arr[i++]
            }
            return cnt
        },
        testArr
    )

There is a difference between reported execution time from plain loops vs loops executed inside of callbacks. Furtermore there is difference in execution time if you run it inside of script tag in head vs execute it in developer console as shown in this images:

1. Result from script tag:

2. Result from console (Firefox):

Can anyone explain why this is happening or provide links to any resource where I can find out any information related to this. Also would appreciate if browser differences would be covered in response or document you will link.

Thank you for your time and help.

Answer 1

• performance.now() is the best option to measure performance.

https://developer.mozilla.org/en-US/docs/Web/API/Performance/now

• end time calculation is wrong. in your mprofile function you calculate a diff BEFORE calling the first console.log, in ordinary code - AFTER the second one. so, in one case you include interaction with console into your measurement, in other - not

• also, the whole example is a bit incorrect. you should create a functions like loop, reverseLoop, etc. and measure time before/after calling them. then you should measure time for the same functions in callbacks. and you should run each case at least 10-times and check avg times.

Answer 2

If you are using Chrome console.time() is pretty useful. e.g:

console.time('myTime1')
console.timeEnd('myTime1') //myTime1: 5047.492ms