View Issue Details

IDProjectCategoryView StatusLast Update
0001988XdebugUncategorizedpublic2021-08-18 12:23
Reporterumulmrum Assigned Toderick  
PrioritynormalSeverityminorReproducibilitysometimes
Status closedResolutionno change required 
PlatformIA64OSUbuntu Linux (PHP in Docker)OS Version20.04
Product Version3.0.4 
Summary0001988: Potentially slow performance of ReflectionMethod::getPrototype
Description

When "develop" mode is activated, calls to ReflectionMethod::getPrototype get very slow (~7ms) in some conditions. I didn't manage to build a simple reproducer, for me this only occurs when building the Symfony DIC container (where this function will be called thousands of times, leading to request durations of 30+ seconds). But for this case the problem is 100% reproducible.
After deactivating Xdebug, duration of the function call is negligible (~2s for the complete request instead of 30s, but this comes from other sources, getPrototype has practically no impact then). Stopping the listener or removing the trigger cookie is not enough; also Xdebug is configured to be activated on trigger only.

Thank you for your work!

Steps To Reproduce

A minimal Symfony project reproducing the issue can be found here: https://github.com/umulmrum/symfony-perf-test (just build the container - let me know if you need a pointer on how to run a Symfony app)
I didn't report this to Symfony as I can't see anything special in their method usage, so thought it might be best here. The problem is reproducible for colleagues using the same Docker setup, so it isn't specific to my machine but might somehow be specific to our setup, though I can't think of any cause (if you have a suggestion, I'm happy to investigate further).

Additional Information

The slowness happens in \Symfony\Component\DependencyInjection\Compiler\AutowireRequiredMethodsPass

TagsNo tags attached.
Operating SystemUbuntu Linux
PHP Version7.4.10-7.4.19

Activities

umulmrum

2021-07-27 09:31

reporter   ~0005943

Did some tests and would like to share the results:

The problem DOES occur on another machine with a plain setup (no Docker, fresh PHP 7.4 install, Xdebug 3.0.4) with the linked simple Symfony app.

The problem does NOT occur when downgrading to Xdebug 2.9.8 using my real-world application (and otherwise unchanged environment). Symfony container build time goes down to ~12s which is expected. As the container grew in the meantime, build time went up to 158s with Xdebug 3.0.4 (with 12507 calls to ReflectionMethod::getPrototype using up 129s = 81% of the wall time according to Blackfire)

Thanks again for your help!

derick

2021-08-06 17:57

administrator   ~0005962

Just acknowledging that I've seen the issue, but I didn't have time yet to try out your docker container.

I suspect that because Xdebug 3 removed a bunch of settings, it is always doing more work creating stack traces. I suspect that the Symfony methods here might include very big objects etc in the function call that happens many times. You can try setting https://xdebug.org/docs/all_settings#var_display_max_depth to a lower value (1, instead of the default 3) to see if that makes things better. If you only care about debugging with Xdebug, then you can set xdebug.mode=debug, and then all the work that Xdebug does in 'develop' mode should not be done.

umulmrum

2021-08-16 09:08

reporter   ~0005982

@derick: Thank you for your reply, that's the right direction. I found that we even configured var_display_max_depth = 10 (maybe I'll find out why) so that seems to be the reason why this problem hurt us more than others. When reducing the value to 3, build time is reduced by half, and when reducing to 1 it's 11s compared to 6s without Xdebug.

Disabling debug mode and setting var_display_max_depth = 3 will reduce wall time to 9s.

So we will definitely use some of your suggestions. If you can find the time I still appreciate optimization on Xdebug's side so that it's harder to shoot oneself in the foot. In any case thanks again :-)

derick

2021-08-18 12:23

administrator   ~0005987

I have already done most of these optimisations with Xdebug 3.0, so I will be closing this issue. There will always be ongoing work on making Xdebug more performant.

Issue History

Date Modified Username Field Change
2021-06-24 06:56 umulmrum New Issue
2021-07-27 09:31 umulmrum Note Added: 0005943
2021-08-06 17:57 derick Status new => acknowledged
2021-08-06 17:57 derick Note Added: 0005962
2021-08-16 09:08 umulmrum Note Added: 0005982
2021-08-18 12:23 derick Assigned To => derick
2021-08-18 12:23 derick Status acknowledged => closed
2021-08-18 12:23 derick Resolution open => no change required
2021-08-18 12:23 derick Note Added: 0005987