Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Performance degradation with JIT #825

Open
alexpts opened this issue May 5, 2021 · 7 comments
Open

Performance degradation with JIT #825

alexpts opened this issue May 5, 2021 · 7 comments

Comments

@alexpts
Copy link

alexpts commented May 5, 2021 •
edited

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
@alexpts alexpts changed the title Strange behavior when JIT is enabled Performance degradation with JIT May 5, 2021
@dantleech
Copy link
Member

dantleech commented May 8, 2021 •
edited

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
Copy link
Author

alexpts commented May 8, 2021 •
edited

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
Copy link
Member

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
Copy link
Member

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

@alexpts
Copy link
Author

alexpts commented May 8, 2021 •
edited

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
Copy link
Member

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

@dantleech
Copy link
Member

dantleech commented Jun 19, 2021 •
edited

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 :/ )

@dantleech dantleech reopened this Jun 19, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@dantleech @alexpts