Add an easy way to write debug statements

I thought I was the only one feeling this way … I've pulled out many hairs over this.

Subscribing.

First, a debugger is well worth the (sizeable) setup effort. I posted some xdebug setup tips related to simpetest (see bottom of page).

For others, I think our only hope is to add a 'messsages' column to the simpletest table which stores a serialized array of messages. Developers could then call drupal_set_message('foo', 'debug'). We'd populate that column when we do the usual INSERT into the simpletest table. We could choose to present each message type separately on the final test results page.

it's actually the test runner that's calling drupal_get_message() the change was made as part of #310358: Add a test for file_save_upload and clean up file.test

Update: I'd initially linked to the wrong issue. Just corrected it

Subscribe.

Sounds like we ought to at least revert that change to drupal_web_test_case.php, but I'm sure there's more that we could do.

@drewish: that code was in the file tests because they incorrectly pass when it's not there, or..?

webchick, i'd had the drupal_get_messages() calls in to clear out all the expected error message that are generated when testing the file functions. someone else--i don't recall who at this point--had suggested moving that up to the test runner.

#296574: Provide debug facility for general and testing

I end up using:

file_put_contents('outout.html', 'data');

works great for seeing what browser is up to:

file_put_contents('outout.html', $this->drupalGetContent());

and of course you can use FILE_APPEND.

I vote for getting something like debug methods, otherwise I'm really not sure what else can be done.

In addition I'm not sure what the intended role of the tests should be. I always though of them as a way to help find bugs, not debug them. That is much more complicated. Perhaps we should decide that and make changes accordingly. Either way having the dump to a file/screen would provide a way to get tests working when your written them, etc.

boombatower, i'd really like to have some kind helper functions for file based logging. one thing i often find myself doing is writing $this->_content to a file to find out why $this->assertText() calls are failing. often times having a file is much nicer than data in the session.

@Crell: I agree, but you're missing something. The situation you're describing, only applies to unit testing (i.e. a piece of well defined code that should return X if passed Y).
But what about functional testing? For example, it's surreal to apply that process when you're designing a form in Drupal: you design the form first, then add testing. After that, a loop begins: refine the form, make the test more granular, repeat.

Anyway, the point still stands: easy debugging is a necessity.

I'v been pondering this and I'll agree know that a filesystem based debug function is all we can hope for. The filesystem is all that persists in our wacky simpletest hyper isolated environment (@Crell - you really should look into scripts/run-tests.sh. you wil have new appreciation for the complexity I think. Or you will sugegst a better way) ... The debug function should live in bootstrap.php since that gets loaded early on. It can't live in simpletest module since thats not enabled in the instance that gets installed (currently this is the 'default' install profile).

Something like:

function drupal_debug($data) {
  // The temp directory does vary across multiple simpletest instances.
  $file = file_directory_temp(). 'drupal_debug.txt';
  if (file_put_contents($file, $data, FILE_APPEND) === FALSE) {
    drupal_set_message(t('The file could not be written.'), 'error');
    return FALSE;
  }
}

I'll give this a try now.

OK, this is proving useful. It is a bit nicer than error_log() because it prints complex variables and outputs an optional label.

patch rolled from /includes because my tree is bit tricked out ATM.

"our wacky simpletest hyper isolated environment"

/me is proud of the isolation since it prevents you having to periodically re-install your testing environment after running tests, not to mention those tests that fail after one test changes something they count on. Drupal's use statics makes this rather hard. It makes writing tests much simpler.

I like the output function. I'll take a look at the patch when I get home.

I suggest the following course of action:

1) we add a "data" column in the test result table, that will be populated:
- with the full page fetched by drupalGet, drupalPost and similar calls
- with the full backtrace on error and exceptions

2) we implement a new drupal_debug function that:
- simply calls dsm() when ran in a normal site
- record a "debug" assertion type (we currently have only 'pass', 'fail' and 'exception') when ran in testing mode. In that case the "data" column could be populated with the full context (local variables, backtrace, etc.)

1. Thats a good start ... A single test can do many drupalGETs. Do you suggest to automatically record all of them? Also, how to present this info? P

2. The assertDebug is a great enhancement, but does nothing for when you are on the 'tested' side. The backtrace and such would be keyed by to the assertion ID? Again, how to present this on the web and in run-tests.sh?

1. Thats a good start ... A single test can do many drupalGETs. Do you suggest to automatically record all of them? Also, how to present this info? P

The impact on performance and storage requirements for this remains to be evaluated. We could also simply record that info when drupalPost processing fails (submit button not found, unmatched fields, etc.).

As far as display is concerned, I'm open to suggestion. Maybe simply adding a "show data" link to the result page, that display this in a new window (or something, I know popups are not really loved these days).

2. The assertDebug is a great enhancement, but does nothing for when you are on the 'tested' side. The backtrace and such would be keyed by to the assertion ID? Again, how to present this on the web and in run-tests.sh?

The information from the tested side could be fetched by the same mechanism put in place by #243532: Catch notices, warnings, errors and fatal errors from the tested side. This is just waiting for Angie to make up her mind on #304924: Extend drupal_error_handler to manage exceptions, that is a dependency.

For display on the web, the same mechanism as (1) could apply. For run-tests.sh, everything remains to be done (you know that the text reporter is awful :p, could you contribute back the one you wrote for Drush?).

"We could also simply record that info when drupalPost processing fails (submit button not found, unmatched fields, etc.)."

The assertions already tell you all of that.

Storing all this data in addition to the already large amount of data stored by assertions seems a bit excessive, at least to do automatically.

Looks like the debug method is up for debate, but I still prefer and will most-likely use a file_put_contents as viewing the actual page as SimpleTest sees it is one of the most useful things I can do. Now this is obviously a difference between Functional (majority of current core tests), and unit testing (by far minority). That is not to say that we shouldn't tailor some of the tools towards unit testing, just to say that SimpleTest is in the state it is based on functional testing.

Unit testing was discussed and washed over in general so much of the good ideas were never implemented.

I suggest some sort of methods that help with unit testing, but don't add extra load to already large load created by functional tests and create the file dumb method that those of us who write functional tests find useful.

how about $this->assertDebug('message'); that gets highlighted in blue or something and instantly gets floated to the top in the test results page?

Lets make this issue focus on unit testing side of thing, since obviously that was the original purpose of this issue.

The other issue I opened can focus on functional testing.

Edit: this should in fact go in the other issue.

chx pointed out that with both #304924: Extend drupal_error_handler to manage exceptions and #243532: Catch notices, warnings, errors and fatal errors from the tested side, adding debugging statements will be uber-easy: simply call trigger_error() (or a very simple wrapper around that we could make), and the error handler will take care of everything for you.

So in fact this should be postponed until #243532: Catch notices, warnings, errors and fatal errors from the tested side (or a variant) goes in. After that, we could consider adding a drupal_debug(), some kind of wrapper around trigger_error().

Sorry boombatower, you were right: we should indeed separate those two issues.

FYI, I committed drupal_debug() and its alias dd() to devel.module. Hope we can get this into D7 though.

I did some testing an trigger_error works great from either side but it can only pass strings. Would be nice to log more complex variables like array/object.

/me still likes a file_put_contents() wrapper.

Subscribing.

Theoretical question: why not start an output buffer before a SimpleTest starts running, get the contents as it ends, and display them as either a SimpleTest exception or on the batch API page?

@#20 and following: Why don't you use a static method, then you can use $this-> in the unit tests, and the static method by className::etc outside.

subscribe

I've also pulled some hairs out over this one.
I'm currently experimenting with file_put_contents(), but it feels a bit clunky and ad hoc (a wrapper like the suggested drupal_debug() makes it a bit better).
(subscribing too)

A note about the usage of devel's drupal_debug() (pun intended):

drupal_debug() writes to a file file_directory_temp(). '/drupal_debug.txt'.

Now, on my setup file_directory_temp was configured to something else than the default.
When I use drupal_debug() outside a simpletest context, it writes to that directory as expected.
However, in a simpletest context (with fresh database tables and configuration) file_directory_temp is just the default (unless changed explicitly in a test function of course), so drupal_debug() writes to the default file_directory_temp instead.

I guess this dual behavior may initiate some (additional) hair pulling, so I thought it deserved to be mentioned it here.

True that. The tested site is virgin Drupal so lots of settings like temp dir are set to defaults. I'm not sure if simpletest lets you configure which install profile it uses - that would be a handy fix. One could use a customized install profile here. Would be great for adding in a base set of data and so on.

You can always just pop the database prefix back to the original, query the {variables} table, and then push it back.

@cwgordon7 - i don't think the tested side knows thye db prefix of the original. you are probably assuming it is no prefix.

you could use a variable override in your settings.php

$conf['file_directory_tmp'] = '/example';

IMO, this should debug function should be in core

The tested side has to know the db prefix of the original, otherwise it wouldn't be able to write assertions to the original database...? Not sure if I understand what you're saying. If you're talking about pages that are called as a drupalGet()/drupalPost(), it's simple enough to pass the original database prefix to those pages.

Grrr.

Yea inside drupalGet()/drupalPost() it would need to be passed....I'll take some time this week and see if I can create some sort of solution.

@Crell: If you point me to the patch, any pointers on how to use it (if necessary), and get that committed I would be happy to work on implementing it within SimpleTest.

Lets focus all conversation at #296574: Provide debug facility for general and testing.