How to find some hooks firing in the background?

[bernhard]

Hello everybody,

I have this allegedly simple hook to clone an invoice:

  public function cloneInvoice($event) {
    // check if this invoice is valid to clone
    $old = $event->object;
    if($old->template != 'invoice') throw new WireException("This is not a valid invoice to clone!");

    // create clone
    $new = $this->pages->clone($old);
    $new->invoicenum = null;
    $new->date = time();
    $new->datedue = null;
    $new->datesent = null;
    $new->datepaid = null;
    $new->pdfs->removeAll();
    $new->save();

    // return newly created page
    $event->return = $new;
  }

The problem is, that $this->pages->clone() creates TWO copies of the page. There must be some other hook firing on page save or the like. But I can't find which one it is and I wonder how you debug such things?

I've once tried something that I called hook-recorder, but that project never saw the light of day. Are you using XDebug? Or are there any tools that can help in such situations? Tracy maybe? The only thing that I know so far is that the code above fires ONCE but creates two copies.

Thank you for your time ? 

[Autofahrn]

Did you try debug_print_backtrace?

https://www.php.net/manual/en/function.debug-print-backtrace.php

Maybe there's a Tracy entrypoint to get this logged properly.

[bernhard]

Hi @Autofahrn,

thx for that suggestion. I did not try that. But I'm not sure how I should/could do that to get a helpful output?

I've found the issue, but would still be interested in a way to show a backtrace of all executed hooks ? I've added a file_put_contents(... FILE_APPEND) to WireHooks::runHooks() to dump all executed hooks to a file called hooks.txt. That could be a first step in the direction that I wish would exist already.

The issue in my case was that my CRM module was loaded twice, so all methods added via hooks actually ran twice. I found that by inspecting the debug mode tools, where my cloneInvoice() method showed up twice (and so did all other CRM hook methods). The solution was to make the module "singular" (and do a module refresh).

But still I think it would be great to have a chronological list of all executed hooks so that one can instantly see which hook fired when (and after/before what other hooks).

 

[Autofahrn]

17 hours ago, bernhard said:

But I'm not sure how I should/could do that to get a helpful output?

At least it would tell you, from where your hook was called. For example, if its a pageSave hook, you'll see who is actually invoking $page->save. In this case you probably had seen, that the hook was invoked twice from the same originator.

If that was a technical question, you'll either do this, to get a preformatted trace of the stack (not sure why I needed DEBUG_BACKTRACE_IGNORE_ARGS in my quick test):

	ob_start();
	debug_print_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
	$preformattedCallStack = '<pre>' . ob_get_clean() . '</pre>';

Or dump the full trace data array using tracy:

	bd(debug_backtrace());

 

[bernhard]

Thx @Autofahrn, but my quick test was at first glance nice, but it seems it is not 100% what I want...

I put this hook in ready.php

$this->addHookBefore("ProcessPageView::finished", function() {
  bdb(debug_backtrace(), 'finished');
});

This looked ok, but then I cloned my site and the "coneInvoide()" method did not show up in the backtrace. I did a debug_backtrace() in that method and - of course - it showed up there and showed a somewhat helpful dump. BUT: The problem is, that often I don't know what is going on where, so you can't just place a debug_backtrace() somewhere in the code, because you simply don't know where you'd have to put it. Do you know what I mean?

Maybe I have to give xdebug another try...

[Autofahrn]

2 minutes ago, bernhard said:

Do you know what I mean?

Sure. Of course the backtrace only helps if you see a function get called (maybe unexpected or with bad parameters) and want know where this call originates from. This, for sure, is not a history log and not an alternative to the proposed hook log.