8000 [2.2.x] Webprofiler - Some called listeners are not shown · Issue #6686 · symfony/symfony · GitHub
[go: up one dir, main page]

Skip to content

[2.2.x] Webprofiler - Some called listeners are not shown #6686

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.

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

Closed
hhamon opened this issue Jan 10, 2013 · 30 comments · Fixed by #9168
Closed

[2.2.x] Webprofiler - Some called listeners are not shown #6686

hhamon opened this issue Jan 10, 2013 · 30 comments · Fixed by #9168

Comments

@hhamon
Copy link
Contributor
hhamon commented Jan 10, 2013

In Symfony 2.2.0-BETA1, I've created a listener that listens to the security.authentication.success and it's perfectly triggered.

But when I look at the Events panel in the profiler application, it's still listed in the Not Called Events section of the panel.

@catchamonkey
Copy link
Contributor

Yes I can confirm this but in 2.2.0-RC3.

I have an initial listener on kernel.request that is triggered and shown in the profiler.
This method then dispatches another event (in some cases) and I listen to that event.
This second event is also triggered, but is under the Not Called section.

@catchamonkey
Copy link
Contributor

I could setup a basic project repo to demo this if it helps?

@fabpot
Copy link
Member
fabpot commented Feb 28, 2013

A fork of the Symfony Standard Edition would definitely help. Thanks.

@catchamonkey
Copy link
Contributor

No problem, will do that today and come back to you.

@catchamonkey
Copy link
Contributor

Hey @fabpot
I've forked and created a branch to show the issue here https://github.com/catchamonkey/symfony-standard/tree/listener_issue

See the diff as a comparison against the 2.2 branch here catchamonkey/symfony-standard@symfony:2.2...catchamonkey:listener_issue

You can pull down, install the deps and run the demo page, app_dev.php/demo/hello/World then look at the events in the profiler, you will see the secondary one i created is in the Not Called Listeners section, but it is being called (uncomment the die within).

@catchamonkey
Copy link
Contributor

Actually i've changed it so the secondary method logs an error when called.
There you can see that is logged in the profiler, but the listener is shown as not called.

@catchamonkey
Copy link
Contributor

And one more thing, if you can give me a starting point as to where you think the issue may be, i'd be happy to have a look and see if I can solve it.

@stof
Copy link
Member
stof commented Feb 28, 2013

@fabpot This is probably because the dispatcher being passed in the event is the inner dispatcher, not the wrapping one (it is always the issue when using composition and the inner object passes $this to another place)

@fabpot
Copy link
Member
fabpot commented Feb 28, 2013

@stof is right and it was done on purpose. Not sure what to do here.

@catchamonkey
Copy link
Contributor

Obviously it has knowledge of all the services tagged as kernel.event_listener, but the EventsDataCollector is only aware of the main dispatcher instance in terms of what it knows has happened to those events?

@catchamonkey
Copy link
Contributor

I've used the sams approach in a long standing 2.0 project which doesn't have this issue.
Is there possibly another way to approach what i'm trying to do that bypasses the issue?

@kriswallsmith
Copy link
Contributor

When in debug mode, debug.event_dispatcher is injected into http_kernel, but event_dispatcher still returns the unwrapped dispatcher. Any events dispatched by services that use event_dispatcher will not be logged.

Why don't we rename event_dispatcher to event_dispatcher.inner and rename debug.event_dispatcher to event_dispatcher? Otherwise I don't see an easy way for user-land services to use the right dispatcher per debug mode…

@fabpot
Copy link
Member
fabpot commented Mar 20, 2013

I did that to avoid too much overhead and I did not anticipated the possible issues. So, I guess we should always inject that debug event dispatcher (don't remember if there were any other reasons for not doing it).

@stof
Copy link
Member
stof commented Mar 20, 2013

@fabpot What should be done 8000 is aliasing the debug dispatcher as event_dispatcher and keeping the original one in a private service (using the pattern described in #5920 btw, so we will maybe finally get a decision on it for next releases). 👍 for keeping the debug dispatcher each time (the remaining issue would be a listener aessing the dispatcher in the event object)

@kriswallsmith
Copy link
Contributor

For the issue @stof raised about the call to $event->setDispatcher($this) … we could add an optional 3rd argument to ->dispatch($eventName, Event $event = null, self $dispatcher = null) and call $event->setDispatcher($dispatcher ?: $this). It's ugly, but is a good workaround for the flaw in this design.

@catchamonkey
Copy link
Contributor

Any other thoughts on this?

@mpdude
Copy link
Contributor
mpdude commented Apr 25, 2013

I have part of a fix over at #7673, but what @catchamonkey demonstrates is that when you use the event_dispatcher service to dispatch an event, the debug.event_dispatcher does not notice it.

The example happens to dispatch the second event that's missed from an event listener, but that is irrelevant. My fix would help there only if he used $event->getDispatcher() to dispatch the second one.

So what's the best practise to re-define/alias the service?

@mpdude
Copy link
Contributor
mpdude commented Apr 26, 2013

Probably we need a decision in the first place whether we want to

  • pass listeners the Dispatcher that was initially used to set off the `Event``
  • or the Dispatcher that actually notifies the listener.

And while we're at it, it is allowed to re-dispatch() an existing Event object, possibly even from a listener in mid-propagation?

@ghost
Copy link
ghost commented Sep 11, 2013

@fabpot have you thought about this anymore? It seems the way we use events they never get logged for the reasons pointed out by @mpdude

@liuggio
Copy link
Contributor
liuggio commented Sep 18, 2013

👍 we have the same issue, this is a little bit annoying because upgrading from 2.1 to 2.3 a lot of functional test fails :(

thanks guys.

fabpot added a commit that referenced this issue Sep 19, 2013
This PR was merged into the 2.2 branch.

Discussion
----------

[FrameworkBundle] made sure that the debug event dispatcher is used everywhere

| Q             | A
| ------------- | ---
| Bug fix?      | yes
| New feature?  | no
| BC breaks?    | no
| Deprecations? | no
| Tests pass?   | yes
| Fixed tickets | #6686, #7673
| License       | MIT
| Doc PR        | n/a

Commits
-------

f65a526 [FrameworkBundle] made sure that the debug event dispatcher is used everywhere
@fabpot fabpot closed this as completed Sep 19, 2013
@fabpot
Copy link
Member
fabpot commented Sep 23, 2013

And now I do remember why I haven't replaced the event dispatcher service with the traceable one. That's because the traceable event dispatcher needs the profiler, which creates a bunch of data collectors that need many services. The same goes for the twig service which needs a bunch of services for its extensions. But, as some of these deps are required by both the profiler and twig, we have some circular references. The easiest way to reproduce is the run the assetic:dump or twig:lint commands on the CLI.

I'm going to revert the referenced PR for now and we are back to the drawing board.

@stof
Copy link
Member
stof commented Sep 23, 2013

@fabpot should the traceable dispatcher really receive the full profiler ? This is the real issue IMO.

IIRC, this was done to be able to track events triggered late in the process, by registering them manually in the profiler instead of relying on collect(). A better fix IMO would be to make the profiler collect late data for all collectors. Currently, the profiler misses DB queries, log messages, emails, etc.. which are sent during a late kernel.response listener or during a kernel.terminate event (I thought there was an issue for this opened a long time ago, but I can't find it anymore). This way, the traceable dispatcher would not need to depend on the profiler anymore to update the profile during kernel.terminate.

@fabpot
Copy link
Member
fabpot commented Sep 30, 2013

#9168 is another attempt to fix this issue. Unfortunately, as this is a rather large patch and a new interface for data collectors, it's going to be only applied on master.

The regression from the previous patch does not exist as I have decoupled the traceable dispatcher from the profiler, but if someone can confirm that there are no other regression with other standard bundles, that would help us a lot.

@ghost
Copy link
ghost commented Sep 30, 2013

I have the same problems, referenced in the PR.

@fabpot fabpot closed this as completed in d866a5a Oct 28, 2013
@craigh
Copy link
craigh commented Nov 5, 2013

@fabpot - I am having trouble with this now also within the context of Zikula and a module called Dizkus. The problem appeared in the last 10 days or so and was tested and working previous to that.

Zikula uses an extended version of Events called hooks. The typehinting is breaking because we've expected EventDispatcher but now are getting TraceableEventDispatcher. and so everything is broken:

ContextErrorException: Catchable Fatal Error: Argument 1 passed to Zikula_Hook_AbstractHandler::__construct() must be an instance of Zikula_EventManager, instance of Symfony\Component\HttpKernel\Debug\TraceableEventDispatcher given in /Applications/MAMP/htdocs/core.git/src/lib/legacy/Zikula/Hook/AbstractHandler.php line 24

@craigh
Copy link
craigh commented Nov 5, 2013

@stof
Copy link
Member
stof commented Nov 6, 2013

@craigh Your typehint should use the interface, not the implementation

@craigh
Copy link
craigh commented Nov 6, 2013

thank you @stof - I changed the typehints (you can see here: zikula/core#1372)

and now I get a new error 😦
full trace: https://gist.github.com/craigh/20085c868349b3446f91#file-zhookissuetrace2

any ideas?

@craigh
Copy link
craigh commented Nov 6, 2013

surely, this is a Symfony error - even my IDE identifies Symfony/Component/HttpKernel/Debug/TraceableEventDispatcher @ line 330 - the $wrapped array key as "Illegal array key type callable"

@stof
Copy link
Member
stof commented Nov 7, 2013

@craigh wrapListener returns a Closure object, which can be used as key in a SplObjectStorage.

It is not a Symfony bug but an IDE bug which does not take into account that closures are objects in PHP.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

8 participants
0