search

DirectoryTree / LdapRecord-Laravel

Multi-domain LDAP Authentication & Management for Laravel.
https://ldaprecord.com/docs/laravel/v3
MIT License
512 stars 54 forks source link

[Bug] Wildcard listeners appending to events with every PHPUnit test started #655

Closed Jacobs63 closed 2 months ago

Jacobs63 commented 6 months ago

This is a continuation of #653

The service provider appends those logging event listeners every time the framework is booted, regardless of whether LDAP is actually used or not.

This means this still slows down the testing process, until the first test that actually uses LDAP and calls the teardown is called.

In real-case scenario, that means I have around 360 test cases that append these listeners, then a slow test which uses LDAP & logs 360*n changes, tears down and resets these listeners.

I don't believe I should be calling the tearDown on every test, since I don't use LDAP in every test.

stevebauman commented 3 months ago

I believe this should be resolved now with with https://github.com/DirectoryTree/LdapRecord/pull/716. Let me know if otherwise and I can re-open this issue.

Jacobs63 commented 3 months ago

Hello,

I've made the issue soon after testing your previous fix.

As I've said, the issue persists but in a different way, as stated above.

stevebauman commented 3 months ago

Thanks for confirming @Jacobs63.

Linking this here so I can resolve later tonight:

https://github.com/DirectoryTree/LdapRecord-Laravel/blob/518fd4c14f839ee9c2d7eb9d4697615f8e18748b/src/LdapServiceProvider.php#L120

stevebauman commented 3 months ago

@Jacobs63 I've made a change that will now only register log event listeners if logging is enabled: https://github.com/DirectoryTree/LdapRecord-Laravel/commit/7ab356542792611d83e65493b928304af54f04aa

Can you confirm if this is what you're referring to? If not, can you link exactly where these listeners are being registered and offer reproduction code examples?

stevebauman commented 2 months ago

Ok fixed in latest v3.3.4 release.

Jacobs63 commented 1 month ago

Hey Steve,

sorry for getting back to you so late! Had other priorities on projects instead of unit tests the past month.

I've updated the package to 3.3.5, however, it did not help. I've done some additional debugging to be able to help you out with the debugging a bit.

The first test that runs after using DirectoryEmulator::setup() still logs a ton of messages as duplicate, I've enabled Spatie's Ray to figure out the first running test in our suite & purposely ran the tests without parallel to be able to get a better understanding.

The first test that uses the emulator is n.o. 478 During this test, all info messages get logged 461 times: image This sort-of correlates with the amount of tests being run in total (and the amount of Laravel application instances being created in the setUp method of our test cases).

Having LDAP enabled/disabled beforehand has no effect.

The screenshot from Ray should perhaps help you out with finding which listeners take care of that and thus finding out what does not get properly flushed when the Laravel application instance tears down.

Jacobs63 commented 1 month ago

Update - checked the related MR you've posted once again, seems like I've disabled the LDAP and not it's logging - setting the ldap.logging.enabled option to false via the PHPUnit LDAP_LOGGING server variable prevents this logging as this gets loaded via env during the framework boot method.

Thanks for the fix, this was a mistake on my side :)

Jacobs63 commented 1 month ago

I've ran profiling on our tests, disabling those logs has a very noticeable impact.

Before: image

After: Well.. those tests are nowhere to be seen in the top 10 slowest tests :)

So either way, it still seems like the teardown is not handled properly, this is more of a workaround, but I'm okay with that, since I don't really see a point in logging this when running our tests.