Unexpected timing result after micro-optimization

I've been doing some experiments with some micro-optimizations and got an unexpected timing result, which I couldn't wrap around my head. I would be very thankful for your suggestions.

Following the code :

def findSmallest(arr):
    smallest = arr[0]
    smallest_indx = 0

    for i in range(1, len(arr)):
        if arr[i] < smallest:
            smallest = arr[i]
            smallest_indx = i
    return smallest_indx


def selectionSort1(arr):
    newArr = []
    for i in range(len(arr)):
        smallest = findSmallest(arr)
        newArr.append(arr.pop(smallest))
    return newArr

def selectionSort2(arr):
    newArr = []
    na = newArr.append
    for i in range(len(arr)):
        smallest = findSmallest(arr)
        na(arr.pop(smallest))
    return newArr

def selectionSort3(arr):
    ap = arr.pop
    newArr = []
    na = newArr.append
    for i in range(len(arr)):
        smallest = findSmallest(arr)
        na(ap(smallest))
    return newArr


import random as r
test = r.sample(range(0,1000000),10000)
test1 = test[:]
test2 = test[:]
test3 = test[:]

if __name__ == '__main__':
    import timeit
    print(timeit.timeit("selectionSort1(test1)", setup="from __main__ import test1, selectionSort1"))
    print(timeit.timeit("selectionSort2(test2)", setup="from __main__ import test2, selectionSort2"))
    print(timeit.timeit("selectionSort3(test3)", setup="from __main__ import test3, selectionSort3"))

On my computer :

3.8686506970000005 #selectionSort1
3.961112386        #selectionSort2
4.0788594190000005 #selectionSort3

The point is that I'd expected that, when I'm isolating the attributes search (newArr.append and arr.pop) for both list out of the loop-scope should give me back the best result. As you've seen from the given results this isn't the case and will be very happy with any help. Thank you in advance

Note: For sure this type of optimization would be relevant for very big lists

Let's dive into that.

For performance analysis I really like cProfile.

Now before comparing the methods, we can get a report on one of them:

if __name__ == '__main__':
    import cProfile

    cProfile.run('selectionSort1(test1)')

And see that:

40005 function calls in 3.408 seconds
Ordered by: standard name
ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    1    0.000    0.000    3.408    3.408 <string>:1(<module>)
10000    3.390    0.000    3.391    0.000 playground.py:1(findSmallest)
    1    0.010    0.010    3.408    3.408 playground.py:12(selectionSort1)
    1    0.000    0.000    3.408    3.408 {built-in method builtins.exec}
10001    0.001    0.000    0.001    0.000 {built-in method builtins.len}
10000    0.001    0.000    0.001    0.000 {method 'append' of 'list' objects}
    1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
10000    0.006    0.000    0.006    0.000 {method 'pop' of 'list' objects}

The vast majority of running time is spent in findSmallest. One can run all three methods for sanity, and see that this is the case in all three of them. So saying that it makes the difference between the methods insignificant would be an understatement.

So let's further reduce the experiment to get better isolation, and grow in scale while we're at it:

def selectionSort1(arr):
    newArr = []
    for i in range(len(arr)):
        newArr.append(0)
    return newArr

def selectionSort2(arr):
    newArr = []
    na = newArr.append
    for i in range(len(arr)):
        na(0)
    return newArr

if __name__ == '__main__':
    import random as r
    import cProfile
    test = r.sample(range(0, 10000000000), 10000000)
    test1 = test[:]
    test2 = test[:]


    cProfile.run('selectionSort1(test1)')
    cProfile.run('selectionSort2(test2)')

And now:

         10000005 function calls in 2.421 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.021    0.021    2.421    2.421 <string>:1(<module>)
        1    1.377    1.377    2.400    2.400 playground.py:82(selectionSort1)
        1    0.000    0.000    2.421    2.421 {built-in method builtins.exec}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.len}
 10000000    1.023    0.000    1.023    0.000 {method 'append' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}


         10000005 function calls in 2.130 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.021    0.021    2.130    2.130 <string>:1(<module>)
        1    1.089    1.089    2.109    2.109 playground.py:88(selectionSort2)
        1    0.000    0.000    2.130    2.130 {built-in method builtins.exec}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.len}
 10000000    1.020    0.000    1.020    0.000 {method 'append' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

The micro optimization can be seen clearly.

One last note - consider big O notation when analyzing and trying to improve performance. Generally speaking the complexity of searching a method in an object's attributes is O(1), while even popping a specified element from a list is generally O(n) where n is the length of the list.

Any way, I believe there are even better ways to explore the magnitude of impact of this particular optimization, but I think this is a good start. Good luck!