Результаты простой проверки времени выполнения противоречат результатам профилирования Xdebug

Question

У меня очень дорогой метод removeColumns(...), что дополнительно вызывается несколько раз. Поэтому я хочу увеличить его производительность. Для анализа результатов оптимизации я использую два инструмента: (1) Xdebug Profiler с Webgrind и (2) простой скрипт измерения времени выполнения (который выполняется в командной строке в тестовом методе PHPUnit):

$timeStart = microtime(true);
for ($i=0 ; $i < 1000000; $i++) {
    // code to measure
    $this->...->removeColumns($testArray, $columnNames, $isWhitelist);
}
$timeStop = microtime(true);
$resultTime = $timeStop - $timeStart;
$cycleTime = $resultTime / $i;
echo number_format($cycleTime, 10, ',', '') . ' sec/run';
die(PHP_EOL . '###' . PHP_EOL);

Но теперь я смотрю на результаты - и вижу, что результаты обоих тоже абсолютно противоречат друг другу.

Результаты выполнения скрипта измерения времени:

variant     sec/run (x69)       sec/run (x1000)     sec/run (x10000)    sec/run (x100000)
1           0,0000121144        0,0000102139        0,0000092316        0,0000089004
2           0,0000115650        0,0000112779        0,0000098540        0,0000098941
3           0,0000228260        0,0000240171        0,0000250236        0,0000800230

difference ms (1-2)     0,0000005494    -0,0000010640   -0,0000006224   -0,0000009937
yield % (1-2)           4,54%           -10,42%         -6,74%          -11,16%
difference ms (1-3)     -0,0000107116   -0,0000138032   -0,0000157920   -0,0000711226
yield % (1-3)           -88,42%         -135,14%        -171,06%        -799,09%

Как видите, оптимизация не удалась. Когда метод вызывается не очень часто, производительность становится лучше, но чем больше вызовов, тем хуже (нелинейный, до 900% потери производительности на 100.000 звонки).

Теперь давайте посмотрим результаты Xdebug Profiler:

variant XDP-filename    XDP-filesize    Calls   Total Self (ms) Total Inclusive (ms)
1       1474536556      445,678 KB      69      77325           77403
2       1474537523      402,208 KB      69      1267            1270
3       1474539908      402,963 KB      69      2443            2455

difference ms (1-2)                             76058           76133
yield % (1-2)                                   98,36%          98,36%
difference ms (1-3)                             74882           74948
yield % (1-3)                                   96,84%          96,83%

Так что тут производительность улучшенных вариантов (2 а также 3) значительно лучше, чем variant 1,

Что здесь не так и как это исправить, чтобы получить адекватные результаты тестирования производительности?

---

Все три варианта метода я оптимизирую:

вариант 1

public function removeColumns(array $table, array $columnNames, bool $isWhitelist = false)
{
    foreach ($table as $rowKey => $row) {
        if (is_array($row)) {
            foreach ($row as $fieldName => $fieldValue) {
                $remove = $isWhitelist
                    ? ! in_array($fieldName, $columnNames)
                    : in_array($fieldName, $columnNames)
                ;
                if ($remove) {
                    unset($table[$rowKey][$fieldName]);
                }
            }
        }
    }
    return $table;
}

вариант 2

public function removeColumns(array $table, array $columnNames, bool $isWhitelist = false)
{
    $tableKeys = array_keys($table);
    $firstRowKey = $tableKeys[0];
    $firstRow = $table[$firstRowKey];
    $allColumnNames = array_keys($firstRow);
    $resultColumns = [];
    foreach ($allColumnNames as $columnName) {
        $remain = $isWhitelist
            ? in_array($columnName, $columnNames)
            : ! in_array($columnName, $columnNames)
        ;
        if($remain) {
            $resultColumns[$columnName] = array_column($table, $columnName);
        }
    }
    $index = 0;
    $resultTable = [];
    foreach ($resultColumns as $resultColumnName => $resultColumn) {
        foreach ($tableKeys as $index => $tableKey) {
            $resultTable[$tableKey][$resultColumnName] = $resultColumn[$index];
        }
    }
    return $resultTable;
}

вариант 3

public function removeColumns(array $table, array $columnNames, bool $isWhitelist = false)
{
    $tableKeys = array_keys($table);
    $firstRowKey = $tableKeys[0];
    $firstRow = $table[$firstRowKey];
    $allColumnNames = array_keys($firstRow);
    $columns = [];
    $i = 0;
    $arrayMapInputVarNames = [];
    foreach ($allColumnNames as $columnName) {
        $remain =
            ($isWhitelist && in_array($columnName, $columnNames)) ||
            (! $isWhitelist && ! in_array($columnName, $columnNames))
        ;
        if($remain) {
            $varName = 'column' . $i++;
            $$varName = $columns[$columnName] = array_column($table, $columnName);
            $arrayMapInputVarNames[] = '$' . $varName;
        }
    }
    $arrayMapInputString = implode(', ', $arrayMapInputVarNames);
    eval('$rows = array_map(null, ' . $arrayMapInputString . ');');
    foreach ($rows as $index => $row) {
        $rows[$index] = array_combine(array_keys($columns), array_values($row));
    }
    $table = array_combine(array_keys($table), $rows);
    return $table;
}

Answer 1

Это то, что ваша функция намеревалась сделать?

<?php
$table=array(
    'col1'=>'val1',
    'col2'=>'val2',
    'col3'=>'val3',
    'col4'=>'val4'
);

$columnNames=array(
    'col2','col3'
);

function removeColumns($table, $columnNames, $isWhitelist = false) {
    if ($isWhitelist) return array_intersect_key($table,array_flip($columnNames));
    return array_diff_key($table,array_flip($columnNames));
}

print 'blacklist:'.var_export(removeColumns($table,$columnNames,false),1).PHP_EOL;
print 'whitelist:'.var_export(removeColumns($table,$columnNames,true),1).PHP_EOL;

выход:

blacklist:array (
    'col1' => 'val1',
    'col4' => 'val4',
)
whitelist:array (
    'col2' => 'val2',
    'col3' => 'val3',
)

но я не измерял производительность. Вы могли бы загрузить вывод xdebug своего кода где-нибудь?