How can I determine where an event was dispatched from in Magento?

Question

I have an extension that is using the catalog_product_after_save event to make a simple index of the products and the attributes for a custom export.

There appears to be some instances where this event if dispatched without all of the product data, so when the index is updated, it's missing data. I have put in a check that will look for some of the required information that is missing, so I believe that it will no longer be an issue, but I would like to log when it happens and where it came from.

So, is there any way to natively determine where the event was dispatched from that I can look at in the observer?

Answer 1

Get familiar with PHP's backtrace functions (debug_backtrace and debug_print_backtrace) or better yet, the Magento/large-object safe version, mageDebugBacktrace.

For example, I have an observer setup for the controller_action_predispatch event. If I put the following in my observer (as an observer may be called twice, you may not want to exit for your specific case)

class Pulsestorm_Requestset_Model_Observer
{
    public function myMethod($observer)
    {
        mageDebugBacktrace();
        exit;
    }
}

and then load the page, I'll get the following output when I attempt to load any page in the system (since that event fires on almost every page)

[1] /magento/app/code/core/Mage/Core/Model/App.php:1343
[2] /magento/app/code/core/Mage/Core/Model/App.php:1322
[3] /magento/app/Mage.php:455
[4] /magento/app/code/core/Mage/Core/Controller/Varien/Action.php:530
[5] /magento/app/code/core/Mage/Core/Controller/Front/Action.php:64
[6] /magento/app/code/core/Mage/Core/Controller/Varien/Action.php:408
[7] /magento/app/code/core/Mage/Core/Controller/Varien/Router/Standard.php:251
[8] /magento/app/code/core/Mage/Core/Controller/Varien/Front.php:176
[9] /magento/app/code/core/Mage/Core/Model/App.php:352
[10] /magento/app/Mage.php:691
[11] /magento/index.php:87

This gives me the simplified callstack up to the point I called mageDebugBacktrace. The [#] is just a list ordering, followed by a : delimited string. The left side of the string (/magento/app/code/core/Mage/Core/Model/App.php) is a PHP file, the right side of the string (1343) is the line number where the method call happened.

The first three calls

[1] /magento/app/code/core/Mage/Core/Model/App.php:1343
[2] /magento/app/code/core/Mage/Core/Model/App.php:1322
[3] /magento/app/Mage.php:455

are the PHP code that dispatched the event itself. For example, line 455 of Mage.php on my system is

$result = self::app()->dispatchEvent($name, $data);

It's (typically, depending on Magento versions/state-of-your-core) the fourth call in the stack that will point to where the event was dispatched.

[4] /magento/app/code/core/Mage/Core/Controller/Varien/Action.php:530

line 530 of Action.php on my system is

Mage::dispatchEvent('controller_action_predispatch', array('controller_action' => $this));

Bingo! Mage::dispatchEvent is the code that dispatches the event, so we've found our dispatch point.

As mentioned, your observer may be being called multiple times — so logging the data with output buffering might be better than a the output/exit used above

    ob_start();
    mageDebugBacktrace();
    $contents = ob_get_clean();
    Mage::Log($contents);

    #If `Mage::log` is failing early in the bootstrap process
    #file_put_contents('/tmp/trace.log', $contents . "\n",FILE_APPEND);

Answer 2

Here is the mageDebugBacktrace function definition:

function mageDebugBacktrace($return=false, $html=true, $showFirst=false)

So after looking into it, Alan's example could be simplified to something like this:

$trace = mageDebugBacktrace(true, false);
Mage::log($trace, null, 'log-name', true);