Performance degradation with JIT

[alexpts]

I have more than 10x performance degradation when enable JIT.

I don`t know it is problem phpbench or JIT.

Git state for reproduce: https://github.com/alexpts/php-mutable-psr7/tree/jit-1

composer install composer bench

I have ~ 3.021μs for benchCreate subject with disabled JIT. I have ~43.159μs for benchCreate subject with enabled JIT.

Can you check this case?

---

System information: Macos 11.3.1, PHP 8.0.5 (cli) (built: Apr 29 2021 16:01:35) ( NTS ) Copyright (c) The PHP Group Zend Engine v4.0.5, Copyright (c) Zend Technologies with Zend OPcache v8.0.5, Copyright (c), by Zend Technologies

JIT config: opcache.enable_cli=1 opcache.enable=1 opcache.jit_buffer_size=32M opcache.jit=1255

[dantleech]

I was also unable to get JIT working effectively - but I don't think this has anything to do with PHPBench.

You can be more explicit by passing the PHP config with a profile:

{
    "profiles": {
         "jit": {
             "runner.php_config": {"opcache.enable_cli": 1, ... }
         }
    }
}

you can then run with --profile=jit and -vvv to see how the PHP process is being spawned.

interested to see if you make any progress.

[alexpts]

My config for phpbench:

{
  "runner.bootstrap": "../vendor/autoload.php",
  "runner.path": "bench",
  "runner.time_unit": "microseconds",
  "runner.progress": "blinken",
  "core.profiles": {
    "jit": {
      "runner.php_config": {
        "opcache.enable_cli": 1,
        "opcache.enable": 1,
        "opcache.jit_buffer_size": "32M",
        "opcache.jit": 1255,
        "xdebug.mode": "off"
      }
    }
  }
}

Run with JIT:

vendor/bin/phpbench run --config=tests/phpbench.json --profile=jit --report=aggregate -vvv
[DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBench5wYqjx'

[DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchtxn9My'

PHPBench (1.0.0-beta2) running benchmarks...
with configuration file: /xxx/tests/phpbench.json
with PHP version 8.0.5, xdebug ❌, opcache ✔

[DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchPmbYfP'

\PTS\Test\Psr7\bench\Response\JsonResponseBench (#0 benchCreateViaClone, #1 benchCreate)

#0  0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchsESIDS'
subject benchCreateViaClone with 4 iteration(s) of 10 rev(s),
para0.200 0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchf3RN4d'

          0.100 0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchUAWvgR'

                0.300 0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchwabN4i'

#0  0.200 0.100 0.300 0.300 (μs) Mo0.270μs (±36.85%)
#1  0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchqovt9a'
subject benchCreate with 4 iteration(s) of 10 rev(s),
#1  42.200  0.000   [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchrV4eg7'

            43.300  0.000   [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchj78R0F'

                    46.200  0.000   [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit_buffer_size=32M -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchf6mdg5'

#1  42.200  43.300  46.200  44.400 (μs) Mo43.531μs (±3.36%)

1 variants failed:

  ✘ \PTS\Test\Psr7\bench\Response\JsonResponseBench::benchCreate # 0

    1) mode(variant.time.avg) < 4 microseconds
       = 43.53072407045 < 4 microseconds
       = false

Subjects: 2, Assertions: 2, Failures: 1, Errors: 0

+-------------------+---------------------+-----+------+-----+----------+----------+---------+
| benchmark         | subject             | set | revs | its | mem_peak | mode     | rstdev  |
+-------------------+---------------------+-----+------+-----+----------+----------+---------+
| JsonResponseBench | benchCreateViaClone | 0   | 10   | 4   | 1.593mb  | 0.270μs  | ±36.85% |
| JsonResponseBench | benchCreate         | 0   | 10   | 4   | 1.593mb  | 43.531μs | ±3.36%  |
+-------------------+---------------------+-----+------+-----+----------+----------+---------+

Script vendor/bin/phpbench run --config=tests/phpbench.json --profile=jit --report=aggregate -vvv handling the bench event returned with error code 2

Run without JIT:

vendor/bin/phpbench run --config=tests/phpbench.json --profile=jit --report=aggregate -vvv
[DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchmkpMYH'

[DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchdoi9RJ'

PHPBench (1.0.0-beta2) running benchmarks...
with configuration file: /xxx/tests/phpbench.json
with PHP version 8.0.5, xdebug ❌, opcache ✔

[DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchubnQYf'

\PTS\Test\Psr7\bench\Response\JsonResponseBench (#0 benchCreateViaClone, #1 benchCreate)

#0  0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchCXBXUg'
subject benchCreateViaClone with 4 iteration(s) of 10 rev(s),
para0.200 0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchqWENkg'

          0.100 0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBench7LkQ5c'

                0.200 0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBench7u4Y7P'

#0  0.200 0.100 0.200 0.200 (μs) Mo0.199μs (±24.74%)
#1  0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchSzTJSj'
subject benchCreate with 4 iteration(s) of 10 rev(s),
para3.700 0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchhSlqdD'

          3.000 0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchsHSo92'

                2.900 0.000 [DEBUG] Spawning process: /usr/local/Cellar/php/8.0.5/bin/php -dopcache.enable_cli=1 -dopcache.enable=1 -dopcache.jit=1255 -dxdebug.mode=off -dmax_execution_time=0 '/private/var/folders/8s/cdp946tj11z2ypm8pmx65jtr0000gn/T/PhpBenchTMh7Yl'

#1  3.700 3.000 2.900 3.000 (μs) Mo2.977μs (±10.16%)

Subjects: 2, Assertions: 2, Failures: 0, Errors: 0

+-------------------+---------------------+-----+------+-----+----------+---------+---------+
| benchmark         | subject             | set | revs | its | mem_peak | mode    | rstdev  |
+-------------------+---------------------+-----+------+-----+----------+---------+---------+
| JsonResponseBench | benchCreateViaClone | 0   | 10   | 4   | 1.593mb  | 0.199μs | ±24.74% |
| JsonResponseBench | benchCreate         | 0   | 10   | 4   | 1.592mb  | 2.977μs | ±10.16% |
+-------------------+---------------------+-----+------+-----+----------+---------+---------+

Do you think problem in JIT?

[dantleech]

I honestly don't know, it's not a problem with PHPBench as it is only spawning a PHP process and running code in it. Possibly something to do with the config.

[dantleech]

You might also try doing a @Warmup(10) so that the JIT is "warmed up" before you start measuring...

[alexpts]

I used @Warmup(1) already.

/**
     * @Revs(4)
     * @Iterations(4)
     * @OutputTimeUnit("microseconds", precision=3)
     * @Warmup(1)
     *
     * @Assert("mode(variant.time.avg) < 4 microseconds")
     */
    public function benchCreate(): void
    {
        new JsonResponse([], 200, [
            'h1' => 1,
            'h2' => 2,
            'h3' => 3,
            'X-lame' => 'some values',
            'foo' => 'asdasd asd asd21 123e12 / 12  /sad',
        ]);
    }

@Revs(1) - 5.000μs @Revs(2) - 4.501μs @Revs(3) - 3.663μs @Revs(4) - 50.243μs @Revs(40000) - 2.051μs

[dantleech]

Closing for now, feel free to carry on the discussion though.

[dantleech]

FWIW I don't think opcache will work with PHPBench because it currently creates a new file for each iteration (and it doesn't have to, so that could be improved). Reopening as it would be worth investigating if that would help here (and if it does, it implies having a warmup iteration also :/ )