Provide debug facility for general and testing

When I create my own debugging routines I output the debug info to watchdog. This allows me to capture quite a bit of information on and view it on a different window.

More talk: #314112: Add an easy way to write debug statements

Per other issue focusing on unit test debugging facility.

I'll work on a patch.

Here is my current state of thoughts for tonight (copied from the other issue):

It would be useful to have additional data when test fails. Those include full page dump for all assertions that check stuff on the page:

From a code perspective, this is not too hard to do (the first step is to add an additional_data column to the test result table). But there is a big UI issue. Maybe we should postpone this until we made up our mind on the new test result page?

I think postponing it would be best...I'll focus on the two UI patches...lets get something figured out.

subscribing... is this going to be implemented ?

#5: Dear god, yes.

Yeah, #5 seems very useful still.

@boombatower - i think we should unpostpone this. code freeze cometh. any thoughts?

Marked #314112: Add an easy way to write debug statements as duplicate.

I have begun.

I think I will split this up into two patches:
1) Verbose mode
2) Debug output function.

This issue will focus on the latter this the first item is a new idea.

EDIT: Other issue created: #500280: Provide a verbose mode for SimpleTest

Also created: #500334: SimpleTest: color debug messages

crucial for getting contrib authors on board with testing.

It seems like this could take advantage of the framework put in place by #443154: Fatal errors in tests not reported as failures.

The patch pulls PHP fatal errors out of the log since it know nows what was the last database prefixed used. Could also pull things out of the prefixed database for debugging.

Something like watchdog() might even make sense:

Probably best to provide SimpleTest function so people are aware of the functionality.

I'll work on this soon.

The biggest problem with providing a function is that on say code running due to a drupalGet() SimpleTest code is not loaded. So the function won't be available.

If we use watchdog() then at least the code is there, but that seems like something hard to document in code itself, considering not too many ppl may read documentation say at d.o/simpletest.

I believe we need a dsm() equivalent function in core. This function would:

* outside of simpletest, do what dsm() does
* in simpletest, simply throw a PHP warning, this warning will be caught by our error handler (from both the parent side and the client side), and could be displayed properly in the simpletest log.

I would have to agree, I like that solution the best. The question is how far to take it. Make a simple dpm() that does some sort or print_r()/var_export() like stuff (maybe even syntax highlight), and allow devel to override with krumo, or include the krumo stuff in core.

Since Drupal is largely a developer platform and has lots of things useful to developers (not to mention SimpleTest itself) it would seem to make sense to include something like this. Usually the only feature I use from devel.

Seems like there is a negative reactions to providing devel like functionality in core (from IRC) and I wasn't sure about it myself. So we won't go there.

I do think that providing a debug method in core that is very simple and work both during SimpleTest and regular context is the only clean, simple, and documentable way to do this.

The key is should it integrate with devel so that when enabled when you use it you get the pretty krumo output or should they use different function names. The advantage of integrating with devel is that the extra code in this function to allow it to work when using simpletest would not need to be duplicated in devel...and developers would only need to remember one debug function.

Integrating isn't necessarily simple/pretty. I don't like the idea of:

Seems like if we do implement such a function that is overrideable it should be done with a hook that registers debug functions. That starts to seem like overkill so them I am left thinking that we choose to not integrate or integrate only with devel.

Once I get a consensus and a name for the function I'll go ahead and write it.

Just to get things off the ground, this is a very basic patch. No SimpleTest integration yet. drupal_register_debug_function() was DamZ's idea...so that solves our overrideable problem in a simple manor.

Will also be effected by #518404: Lock down DB config based on simpletest UA headers

This seems to do the trick.

The last submitted patch failed testing.

I think this is a very simple base implementation that we can expand on.

What I would like to see is:

• If page is being completed and about to be rendered dump all debug statements as drupal_set_message(). If a suppress variable is on then they won't be displayed. Krumo (devel) would then run here...need to cache variables in some format. Reason being if site crashes and all my debug statements are dpm() [krumo] then I have to change them to dd() to see anything...should just be automatic.
• SimpleTest read the log file and place the debug statements in assertion list.
• Possibly provide backtrace information.
• Format message similar to PHP's messages. At least include file and line that debug was called in.
• During verbose mode in SimpleTest read the log after every drupalGet/drupalPost so the messages are displayed in context. (same with fatal errors)

documentation.

The last submitted patch failed testing.

Can we remove that bugged test already??

Part of that test has been removed. Lets see what happens.

Cross-referencing with possible exception handling change: #522746: Drupal Exception Wrapper Class

If a test throws an exception rather than just doing a watchdog and return or trigger_error, you could potentially pull additional info out of the DrupalException object.

I think that is separate, but interesting none the less.

This will integrate with #443154: Fatal errors in tests not reported as failures

Provides debug facility for general core use and the SimpleTest integration display debug messages in assertions table with group debug.

#500334: SimpleTest: color debug messages will color the messages so they are easy to distinguish.

The current method is insufficient since SimpleTest reader assumes each message in on a single line and that may not always be so. The question begged, is should they be inserted directly into SimpleTest assertions table or, should we store them in a more complex text format or database.

Eventually I see the general debug statements being displayed via drupal_set_message() in a similar manor to devel, but without krumo.

Much better format output with backtrace details, thus eliminating the multi-line issue above. I'll work on designing and implementing the drupal_set_message() portion for regular debugging.

Note: the screenshot has the debug color patch applied.

Code in block.test:

Code in block.admin.inc

This also demonstrates that the backtrace works properly when using the wrapper dd() or drupal_debug().

Documented and added drupal_set_message() when error_level is set to ERROR_REPORTING_DISPLAY_ALL. Since the default reporting level for Drupal 7 HEAD is ERROR_REPORTING_DISPLAY_ALL I used that as well, but that means it will need to be changed along with the all other defaults when a stable release is made. I am not sure if that needs to be documented somewhere or what.

EDIT: missed the SimpleTest functions when documenting...will fix.

Fully documented.

NOTE: This will break devel 7.x, so once this gets in we should place an issue in devel queue to use the register function to override drupal_debug() behavior. Devel should define devel_debug() or devel_drupal_debug() to be properly namespaced instead of dd() anyway.

After a very long conversation with chx in #drupal-dev we decided to take advantage of the error handling built into PHP through trigger_error() and simply provide a wrapper. The wrapper will server to provide documentation and dump the data passed to it so that dd() is still enough (short and sweet).

The debug messages are now concerted exception which we agreed will ensure that they are removed before committing. I will convert the verbose output to exceptions in a followup patch.

Further reduction, remove drupal_debug() and only provide dd().

More minification. :)

Now, that's better. Small patches++

Followup: #539114: Update verbose messages to be exceptions

Why?

I thought we removed drupal_debug? If so, we no longer need it here.

/for/ outputting, probably.

Also, is it possible to write tests for this?

23 days to code freeze. Better review yourself.

Edited the patch file itself so it's good to go.

Ok, some feedback after having tried this out.

1. Debug messages are currently coming up as exceptions. They shouldn't be. It muddles the results of the test:

2. When using dd() outside of the SimpleTest context, the results are pretty nasty:

It'd be nice if we could at least replace that "User notice" with "Debug" and use a neutral grey colour here as well.

3. Core's dd() does nothing like what Devel's dd() does. Yes, I know core takes precedence over contrib, and APIs change on a whim, etc. but it still seems like we're needlessly introducing a major developer WTF here. I'd suggest just using d() for debug, like we have t() for translate and l() for link. There are no core functions that I'm aware of that are two characters, except st() which is an alternate form of t(). Alternately, what the heck is wrong with just plain old "debug()"? :P

The latter part about what it does outside of SimpleTest context is due to the changes made after #37. Chx and I changed it to use trigger_error() instead of my custom logging utility, but as webchick noted it doesn't work so well outside of the context. #37 should work like we want...perhaps we should try that out and we can minimize from there.

Alright.

This should fix all outstanding issue...and even adds a test to simpletest.test.

The last submitted patch failed testing.

I must say this is a good one:

error_test_generate_warnings() contains:
trigger_error("Drupal is awesome", E_USER_NOTICE);

Notice anything weird there? (no pun intended)

Fixed in patch and solve test issue.

The last submitted patch failed testing.

Missed another instance of User notice.

The last submitted patch failed testing.

Small update for t() $args.

I think this addressed webchick's concerns.

I'll leave it up to webchick to drive this patch home. My personal take is that the way we mess around with PHP error types (e.g. 'User notice') is a bit of a hack.

The code still seems to use 'User notice' instead of 'User warning' but maybe I misunderstood parts of it. Doesn't this patch prevent other code from using 'User warning' and 'User notices'? That would be bad, IMO.

To clarify, while we are using user notices for our purposes, it's not like others can't. Currently if you throw a trigger_error it will show up as a Drupal error message after this patch it will be a normal message. It's still there, just the class has changed. And instead of "User notice:" it will say "Debug:". To show an error, everyone uses drupal_set_message, that's why it's there, otherwise you error message includes the "User notice:" which is not cool so I doubt throw_error saw a lot of usage in Drupal (never met anyone using it). And yes using trigger_error is a bit of a hack, however we get a (almost) free ride on the back of the existing error handling infrastructure, otherwise we need to add quite a bit of code -- to get the same infrastructure. That's a waste for debug.

And to clarify further, only trigger_error produces E_USER* stuff, that's not something normally comes around.

That probably was not clear enough. What trigger_error does is always specified by the error handler running. Drupal's error handler already changes what PHP's error handler does. It's not specified anywhere at all what Drupal's error handler should do with the messages passed through trigger_error. So far, almost as an afterthought we put the displayed drupal message in the error class and prefixed the message with "User notice:". We now give it another class and prefix with "Debug:". As we have no specs neither is more correct than the other. The message is displayed, logged etc all the same.

Update patch per request by webchick to use warning icon for debug messages. I have attached screenshot.

This patch is ready to go and would be useful to have available during the testing sprint.

Ugh on laptop...not setup...this is teh patch.

Ok, I've committed this to HEAD.

Like Dries, I too worry about the hackishness of taking over trigger_error, and am concerned about the WTF this brings to PHP developers new to Drupal. But chx does have a good point at #58 that Drupal is defining its own error handler which takes precedence over trigger_error() anyway.

With the commit of this patch, we can satisfy the code freeze requirement to get all function changes in, yet clean-up the implementation later if necessary.

This change needs to be documented in the upgrade docs.

Greggles added documentation, but it used the format from the initial post which is incorrect. I correct: http://drupal.org/node/394976.

Automatically closed -- issue fixed for 2 weeks with no activity.

Unfortunately the documentation gives no guidance about when/where to insert a debug statement like:

It's all rather circular.

Can we have a clear example of how one might use a debug feature for simpleTest?

http://blog.boombatower.com/drupal-7-debug-and-simpletest-verbose

Thanks!