SimpleTest has gotten to the point where you can no longer simply use drupal_set_message to output debug information. This is partly due to batch API implementation.

I propose adding some helper functions for debugging, something simple.

Either a way to collect debug messages to display on results page (could just use assertions, but not a nice), or just a output console of sorts which dumps messages to a file.

$this->debug('debug information');

Comments?

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

boombatower’s picture

Title: Provide a way to output Debugging information in SimpleTest » Provide a way to output debug information in SimpleTest
Anonymous’s picture

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.

boombatower’s picture

boombatower’s picture

Title: Provide a way to output debug information in SimpleTest » Provide debug facility for functional testing

Per other issue focusing on unit test debugging facility.

I'll work on a patch.

Damien Tournoud’s picture

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:

Testing | #314112

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?

boombatower’s picture

Status: Postponed (maintainer needs more info) » Postponed

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

andreiashu’s picture

subscribing... is this going to be implemented ?

RobLoach’s picture

Status: Postponed » Active

#5: Dear god, yes.

moshe weitzman’s picture

Yeah, #5 seems very useful still.

moshe weitzman’s picture

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

boombatower’s picture

Title: Provide debug facility for testing » Provide debug facility for functional testing
boombatower’s picture

Title: Provide debug facility for functional testing » Provide debug facility for testing

I have begun.

boombatower’s picture

Title: Provide debug facility for functional testing » Provide debug facility for testing

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

boombatower’s picture

moshe weitzman’s picture

Priority: Normal » Critical

crucial for getting contrib authors on board with testing.

boombatower’s picture

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:

watchdog('simpletest', 'Debug info!');

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

I'll work on this soon.

boombatower’s picture

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.

Damien Tournoud’s picture

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.

boombatower’s picture

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.

boombatower’s picture

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:

if (module_enabled('devel')) {
  // use its stuff
}
else {
  // core
}

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.

boombatower’s picture

Title: Provide debug facility for testing » Provide debug facility for general and testing
boombatower’s picture

FileSize
1.33 KB

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.

boombatower’s picture

boombatower’s picture

Status: Active » Needs review
FileSize
2.61 KB

This seems to do the trick.

Status: Needs review » Needs work

The last submitted patch failed testing.

boombatower’s picture

Status: Needs work » Needs review

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)
boombatower’s picture

FileSize
2.61 KB

documentation.

Status: Needs review » Needs work

The last submitted patch failed testing.

boombatower’s picture

Can we remove that bugged test already??

boombatower’s picture

Status: Needs work » Needs review

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

kwinters’s picture

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.

boombatower’s picture

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

boombatower’s picture

boombatower’s picture

FileSize
4.04 KB

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.

boombatower’s picture

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.
drupal debug

Code in block.test:

<?php
 
function testBox() {
   
// Add a new box by filling out the input form on the admin/structure/block/add page.
   
$box = array();
   
$box['info'] = $this->randomName(8);
   
$box['title'] = $this->randomName(8);
   
$box['body'] = $this->randomName(32);
   
$this->drupalPost('admin/structure/block/add', $box, t('Save block'));
   
dd('bar', 'foo');
   
drupal_debug('Some random test of data dump: ' . print_r(array('foo' => 'bar'), TRUE));
   
dd(array('foo' => 'bar'));
  }
?>

Code in block.admin.inc

<?php
function block_admin_display($theme = NULL) {
  global
$custom_theme;
 
// If non-default theme configuration has been selected, set the custom theme.
 
$custom_theme = isset($theme) ? $theme : variable_get('theme_default', 'garland');
 
// Fetch and sort blocks.
 
$blocks = _block_rehash();
 
usort($blocks, '_block_compare');
 
dd('not in test process!');
  return
drupal_get_form('block_admin_display_form', $blocks, $theme);
}
?>

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

boombatower’s picture

FileSize
6.92 KB

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.

boombatower’s picture

FileSize
7.82 KB

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.

boombatower’s picture

FileSize
3.2 KB

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.

boombatower’s picture

FileSize
2.63 KB

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

boombatower’s picture

FileSize
2.56 KB

More minification. :)

chx’s picture

Status: Needs review » Reviewed & tested by the community

Now, that's better. Small patches++

boombatower’s picture

webchick’s picture

Status: Reviewed & tested by the community » Needs work
+++ modules/simpletest/drupal_web_test_case.php	3 Aug 2009 21:06:42 -0000
@@ -376,6 +376,11 @@
+    if ($group == 'User notice') {
+      // Instead of 'User notice' set by trigger_error(), use 'Debug'.
+      $group = 'Debug';
+    }

Why?

+++ includes/common.inc	3 Aug 2009 21:06:41 -0000
@@ -895,9 +895,11 @@
+  $blacklist = array('dd', 'drupal_debug');

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

+++ includes/common.inc	3 Aug 2009 21:06:41 -0000
@@ -4847,3 +4849,24 @@
+ * Debug function used to outputting debug information.

/for/ outputting, probably.

Also, is it possible to write tests for this?

23 days to code freeze. Better review yourself.

chx’s picture

Status: Needs work » Reviewed & tested by the community
FileSize
2.55 KB

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

webchick’s picture

Status: Reviewed & tested by the community » Needs work
FileSize
118.78 KB
92.92 KB

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:

Test result | localhost.png

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

Preview | localhost.png

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

boombatower’s picture

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.

boombatower’s picture

Status: Needs work » Needs review
FileSize
8.77 KB

Alright.

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

Status: Needs review » Needs work

The last submitted patch failed testing.

boombatower’s picture

Status: Needs work » Needs review
FileSize
10.07 KB

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)

warning != notice

Fixed in patch and solve test issue.

Status: Needs review » Needs work

The last submitted patch failed testing.

boombatower’s picture

Status: Needs work » Needs review
FileSize
11.13 KB

Missed another instance of User notice.

Status: Needs review » Needs work

The last submitted patch failed testing.

boombatower’s picture

Status: Needs work » Needs review
FileSize
11.13 KB

Small update for t() $args.

chx’s picture

Status: Needs review » Reviewed & tested by the community

I think this addressed webchick's concerns.

Dries’s picture

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.

chx’s picture

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.

chx’s picture

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

chx’s picture

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.

boombatower’s picture

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.

debug with warning

boombatower’s picture

FileSize
11.46 KB

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

webchick’s picture

Status: Reviewed & tested by the community » Needs work
Issue tags: +Needs documentation

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.

boombatower’s picture

Status: Needs work » Fixed

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

Status: Fixed » Closed (fixed)

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

mgifford’s picture

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

<?php
$this->debug('debug information');
?>

It's all rather circular.

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

boombatower’s picture

mgifford’s picture

Thanks!

gupta324’s picture

Issue summary: View changes
David_Rothstein’s picture

Drupal treating all E_USER_NOTICE messages as if they were debug messages means you can't simply call trigger_error('some text') in your code and have it behave like you expect it would. This is causing specific problems in #2844716: "Missing/moved modules" PHP warnings should be PHP notices instead].

I have posted a patch at #2844732: Drupal treats all user-level PHP notices as debug messages to make it so only messages triggered via the debug() function get treated this way, rather than all E_USER_NOTICE messages.