Early Bird Registration for DrupalCon Portland 2024 is open! Register by 23:59 PST on 31 March 2024, to get $100 off your ticket.
Right now if there is a PHP fatal error during execution of tests, one has to both guess that this is the case and dig into the PHP error logs to find the true cause.
However, error logging in PHP is PHP_INI_ALL, so we can alter it at run time just for the tests. We already create a writable directory for each test that runs - that directory is abandoned in the case of a ftal error, which perhaps we can use to trap logged errors.
Comment | File | Size | Author |
---|---|---|---|
#80 | 443154-fatal-errors.patch | 10.29 KB | boombatower |
#77 | 443154-fatal-errors.patch | 10.3 KB | boombatower |
#74 | 443154-fatal-errors.patch | 10.14 KB | boombatower |
#73 | 443154-fatal-errors.patch | 10.14 KB | boombatower |
#72 | 443154-fatal-errors.patch | 8.4 KB | boombatower |
Comments
Comment #1
pwolanin CreditAttribution: pwolanin commentedseems to work if, for example, I alter a function calls in one of the test cases to generate a "PHP Fatal error: Call to undefined function".
Comment #2
pwolanin CreditAttribution: pwolanin commentedtypo fix.
Comment #3
boombatower CreditAttribution: boombatower commentedThis looks great.
Comment #4
Dries CreditAttribution: Dries commentedLooking at the screenshot in #3, it sounds like we can clean-up the output a bit. The two first bullet items seem redundant? It might complicate the code though.
Personally, I wish the tests could write to the watchdog table of the master site, instead of introducing a special logging case. This might be a lot easier now with DBTNG.
Comment #5
pwolanin CreditAttribution: pwolanin commented@Dries - this is for fatal errors. i.e. WSOD. You lose the ability to do anything within PHP, hence the only way to handle this is via the PHP error log as far as I know. Drupal cannot watchodg these sorts of errrors.
Comment #6
Dries CreditAttribution: Dries commentedD'oh -- you're right.
Comment #7
c960657 CreditAttribution: c960657 commentedDon't you see the error message like in this screenshoot from #313902: DX: Show fatal errors in tests? If not, does it work if you add ini_set('display_errors', '1') to DrupalWebTestCase::setUp() ?
AFAICT the patch only works for fatal errors on the testing side, not on the tested side (i.e. on pages fetched using $this->drupalGet()). Can it be extended to do both?
Comment #8
pwolanin CreditAttribution: pwolanin commentedHmm, good question - I think you're right in that we'd need to add these ini directive to the system under test as we do setting the DB prefix.
Comment #9
Dries CreditAttribution: Dries commentedWe need to get this one in! Tagging.
Comment #10
jrchamp CreditAttribution: jrchamp commentedIf you're looking for one to test on, the fix for the fatal error that I was experiencing in the modules/php/php.test #493296: Patch for a couple tests with an error is postponed until this issue is resolved.
Comment #11
Dries CreditAttribution: Dries commentedBumping this to critical because it causes us to waste time in the issue queue, and because some other patches are now blocked on it.
Comment #12
webchickSubscribing as well. Sorry, I committed the fix for jrchamp's problem in another issue an attempt to get more testing slaves online; didn't know it was blocked on this.
Comment #13
catchThis isn't a feature request, broken patches are getting committed with fatal errors in tests because they 'pass'.
Comment #14
scor CreditAttribution: scor commentedpatch #2 does not apply any more. rerolling
Comment #15
chx CreditAttribution: chx commentedIterating the files directory is not something I can agree with. If we have no better idea then create a files/simpletest directory and work in there , I rather have files/simpletest/123 than iterating the whole of files. (NowPublic has a couple million files there for eg)
Comment #16
chx CreditAttribution: chx commentedAlso? That's a DSM. How does that become an assert failure?
Comment #17
boombatower CreditAttribution: boombatower commentedCurrently working on this.
Also note that the patch won't work for run-tests.sh and if multiple testing sessions are run at once it will screw up...or if clean button is not used. Although if we do this right we might be able to eliminate clean button.
This leads into the cleanup of the test runner I am working on which would make one set of code run for start/end of test..etc.
Comment #18
boombatower CreditAttribution: boombatower commentedSplit of files directory change to: #512104: Simpletest breaks high volume sites
Warning is separate issue: #512108: SimpleTest: Add warning to use "Clean environment" button when test run fails
Comment #19
boombatower CreditAttribution: boombatower commentedThis needs a bit more cleanup and documentation and needs a quick code addition in run-tests.sh. In the mean time I would like to see what the bot thinks. It also needs to depend on other patch and have those parts removed.
A possible followup patch could auto-run cleanup since we now know the database prefix that crashed. :)
Comment #20
boombatower CreditAttribution: boombatower commentedrun-tests.sh integration...now we can see if core has any fatal errors
Comment #21
boombatower CreditAttribution: boombatower commentedDocumented and cleaned. This still has the file directory structure patch applied...for testing. Once other is committed I can easily remove it.
Comment #22
boombatower CreditAttribution: boombatower commentedDependent patch. Requires #512104: Simpletest breaks high volume sites
It passes since no log file is found and it simply ignores the code.
Comment #23
BerdirI assume the tests here will fail once it is working correctly, because we have currently two issues with calls to non-existing functions.
This means that we need to fix those two issues first before we can commit this. On the other side, we can use them to verify that it is working as expected.
#395472-241: Plugin Manager in Core: Part 1 (backend)
#373201-37: Enhance drupal_render() themeing. Return renderable array on tracker page.
Comment #24
Dries CreditAttribution: Dries commentedI was initially confused about assertStatic(). It doesn't return TRUE or FALSE, instead it enters something in the database. In fact, it doesn't even perform an assert. I suggest renaming the function to be less confusing, say logAssert() or something.
That said, I went ahead and committed this patch. Given that this de-blocks us, we can clean it up some more in follow-up patches. Marking 'code needs work'.
Comment #25
catchThis doesn't actually show up the fatal errors yet - because we have them in HEAD still, so I guess there's more work to do in this issue.
Comment #26
BerdirAlso, after an error occured, I'm getting the following exception:
PDOException: SQLSTATE[42S22]: Column not found: 1054 Unknown column 'last_prefix' in 'field list': SELECT last_prefix FROM {simpletest_test_id} WHERE test_id = :test_id; Array ( [:test_id] => 9 ) in simpletest_log_read() (line 224 of .../d7/drupal/modules/simpletest/simpletest.module).
(Web and cli)
Comment #27
jrchamp CreditAttribution: jrchamp commentedI had to look up the schema. Disabling and reenabling the simpletest module did not resolve it.
alter table simpletest_test_id add last_prefix varchar(60) not null default '' comment 'The last database prefix used during testing.';
Comment #28
boombatower CreditAttribution: boombatower commentedNeed to re-install module.
Can someone point me to the fatal errors...that we have in core. I tested this is a call to non-existent function and it worked great.
Comment #29
Berdirdrupal_render() has been fixed, #395472-241: Plugin Manager in Core: Part 1 (backend) is still open. these are in FileTransferTest.
I figured that much, but still.. if it would work as expected, all tests should now fail...
Comment #30
scor CreditAttribution: scor commentedIn the System > FileTransfer unit tests:
Fatal error: Call to undefined function dd() in /Applications/MAMP/htdocs/d702_filter/modules/simpletest/tests/filetransfer.test on line 122
though might be specific to my MAMP installation.
Comment #31
boombatower CreditAttribution: boombatower commentedTry this patch out.
Comment #32
boombatower CreditAttribution: boombatower commentedAs discussed in IRC, I cannot re-create this and when I test the patch and such it picks up fatal error.
Comment #33
boombatower CreditAttribution: boombatower commentedPer #24, I agree that it is not clear and have attached patch to correct.
Comment #34
boombatower CreditAttribution: boombatower commentedDocumentation addition, and fixed method call.
Comment #35
jrchamp CreditAttribution: jrchamp commented"recorder" should be "recorded" in:
Comment #36
webchickQuestion. If this patch actually works, how is it passing tests atm? Shouldn't the dd() in the testCopyDirectory() test cause it to always fail?
Comment #37
jrchamp CreditAttribution: jrchamp commented@webchick It correctly failed for me when the fatal error occurred. However, the test bot likely uses a different method for evaluating tests whose fatal errors are not handled by this patch.
The web interface makes a series of AJAX calls pulling each test at a time. The test bot likely runs them directly. I'm not sure who to ask about the test bot's procedure for running these tests so that we could identify a way for it to handle these types of errors as well.
Comment #38
webchickIMO the point of this patch should be for test bot to fail spectacularly when someone adds dd() in their patch. If it doesn't do that, then it doesn't resolve the issue. Although it's nice that it allows for the manual case, that's not what's causing us to completely break HEAD periodically.
Comment #39
webchickAlso, the manual case wouldn't catch this kind of stuff to begin with. I'm sure whoever rolled the Plugin Manager patch had Devel module on their copy of Drupal, and dd() wouldn't have flagged an error for them.
Comment #40
boombatower CreditAttribution: boombatower commentedIt works for both the web runner and run-tests.sh.
/me tired of clarifying how test bot works
Test bot simply invoked run-tests.sh and pulls results out of db...so if run-tests.sh catches it...bot will.
Comment #41
boombatower CreditAttribution: boombatower commentedUpdated for #35.
This is simple fix...main patch already committed...so lets get this in.
Comment #42
boombatower CreditAttribution: boombatower commentedCreate #515998: Bot test - catch fatal error to test with bot.
Comment #43
boombatower CreditAttribution: boombatower commentedCannot test locally since test craps in a different way locally.
Try this out.
Comment #44
boombatower CreditAttribution: boombatower commentedBasically the issue is that logging isn't enabled on drupalGet|Post() side, only test side. This is why I can get it to pick up errors, but test doesn't.
Also require tweak for run-tests.sh edge case.
Comment #45
boombatower CreditAttribution: boombatower commentedOk...this temp...till I figure out where to put it.
Comment #46
boombatower CreditAttribution: boombatower commentedOk, I got this figured out. Need a bit of time to come up with solution...the underlying code is mad.
Comment #47
boombatower CreditAttribution: boombatower commentedThis should fix issue for bot.
This is not a clean fix and still needs work, just want to see if both notices fatal.
Comment #48
boombatower CreditAttribution: boombatower commentedOk, one hell of an ugly patch. Needs cleanup.
Comment #50
boombatower CreditAttribution: boombatower commentedProgress!
This is a delicate matter and the previous patch a debug statement that may have caused errors...removing to see.
Comment #52
boombatower CreditAttribution: boombatower commentedGotta love how sensitive this stuff is.
Comment #53
boombatower CreditAttribution: boombatower commentedNot catching dd() issue since test is not written properly.
/me glares at the author.
Notice anything missing?
Comment #54
webchickboombatower and I have been going back and forth on IRC all day since I can reproduce the bug and he couldn't. The next patch should be the one that allows his changes to work on my machine.
Comment #55
boombatower CreditAttribution: boombatower commentedConfirmed by webchick...that was the issue.
Updated patch should parse stack trace and changed default line number to 0.
Comment #56
boombatower CreditAttribution: boombatower commentedParse PHP stack.
Comment #57
Dries CreditAttribution: Dries commentedI wonder if this opens a security door:
It basically enables people to write to an error.log stored in the publicly accessible file directory. This change makes me a bit nervous.
I've done some reading on php.net and I think error_get_last() in combination with a shutdown function could make for a more elegant solution: (i) it avoids error parsing and (ii) it avoids writing to files (that can be read by the world). See http://us2.php.net/manual/en/function.error-get-last.php. I believe custom shutdown functions are always called.
Thoughts?
Comment #58
boombatower CreditAttribution: boombatower commentedSeems as though a shutdown hook won't work...I tried that first.
Problem is the shutdown hook loses all context (especially depending on the OS configuration). Meaning It loses the drupal root directory and is running in a separate PHP process so you can't just call the db layer and write the assertion.
Again, simpletest is not intended to be installed on live sites...for a number of reason. It should ONLY be used on development computers. It may be a good idea to add some sort of warning.
Another option is to ensure that the database with that prefix exists before doing anything like enabling logging since only SimpleTest can create the prefixed db.
Considering the damage SimpleTest can do to a production site if a test screws up...and the fact that it is a development tool...it should not be placed on a production server even as it now, without this patch.
For example as the issue with the other test I was having trouble with. If you don't add the parent::setUp() SimpleTest will modify the live site.
I'll try and clean up this patch soon.
Comment #59
chx CreditAttribution: chx commentedMeaning It loses the drupal root directory and is running in a separate PHP process so you can't just call the db layer and write the assertion.
hm, the shutdown functions registered with register_shutdown_function definitely run in the same process and I believe the objects are not yet destructed so the DB connection should be there. Care to enlight me what and how did you test to reach this conclusion?
Comment #60
Damien Tournoud CreditAttribution: Damien Tournoud commentedThis will not flight, (1) for the reason described by Dries above and (2) because it makes it impossible to write proper error_log() statement in your code (which I do a lot during debugging).
Given that...
run-tests.sh
, which prints the fatal errors in its standard output, and... I'm close to won't fixing this issue. The only real bug seems to be in PIFR, that doesn't parse the run-tests.sh results for fatal errors.
Comment #61
boombatower CreditAttribution: boombatower commentedPIFR does not and should not parse the text...that is troublesome, inaccurate, and slow (11,000 assertion messages and fatal log messages to regex, catch the test and group they are related to...why?). It reads the results out of the db, as it should. The fatal errors NEED to be failed assertions. The test NEED to fail locally as well as on test servers...consistent results, otherwise we'll have more people complaining that the bot reports errors they don't see...that is the last thing I need.
When debugging you can simply do trigger_error() and it will be picked up...plus we need to work on the facility all together. If you prefer a file with all your output...file_put_contents('out.txt', 'stuff', FILE_APPEND).
This needs to be fixed, this solution (in design, not current code) is clean and works well. It even catches XDEBUG stack trace and provides it on the assertions page.
Seems like the outstanding issue #1 is to confirm that this is a developer tool (as it only can be...it does not add to user experience of a site) and should be treated like one. So the code needs some flags in places to ensure that simpletest is enabled or w/e and then and only then should it allow the error log to be printed. (I think this is what Dries meant)
I'll look into shutdown hook again, but that really does not seem like the solution as per my previous experience and when I played with it. It looses way too much context, and we won't be able to catch XDEBUG and such.
Comment #62
pwolanin CreditAttribution: pwolanin commented@Dries - re #57, in general I think we need some sort of more careful check that we are actually running tests before respecting this UA header.
I can think of a few (a bit ugly) possibilities - we can check that a matching table is in the DB. We could check that the matching simpltest files director has been created, we could put a file in the Drupal tmp dir and even include a timestamp inside it as content so that we limit the time window over which we will accept this header.
Anyhow - we have some bare protection now to prevent the installer from being run with this header, but I agree with the general nervousness about sec holes being possible via the testing code.
Comment #63
boombatower CreditAttribution: boombatower commentedSomething we had in SimpleTest when it went in core originally (or close to that time) was a key that was used in addition to the db prefix to confirm that SimpleTest was the one sending the prefix. The key is much easier to check than other methods (db or files), but technically isn't quite as secure. Once someone figures out the key (not easy of course) it doesn't matter if SimpleTest is doing anything. Although we can just neglect to generate the key until SimpleTest is installed...end remove the key on uninstall.
Not sure if drupal_get_private_key() would be of use here to use as the key.
Personally that the key seems like the simplest and least expensive option. One issue to consider although is that we need a way to check before invoking the db.
Comment #64
pwolanin CreditAttribution: pwolanin commentedSince it's kind of unrelated, a separate issue : #518404: Lock down DB config based on simpletest UA headers
Let's discuss security there - I can roll a generic validation function for the UA header so just get it working here asap.
Comment #65
Damien Tournoud CreditAttribution: Damien Tournoud commented@boombatower: last time I looked, PIFR was parsing the result of run-tests.sh. Maybe that changed in PIFR2?
Comment #66
boombatower CreditAttribution: boombatower commentedYea, in pifr 2 it reads DB...which is much better. Since we are trying to deploy that now it doesn't make sense to be messing with PIFR 1.x, not to mention that it needs to be an assertion so it fails locally.
Reading out of text that PHP just dumps is not a clean and is a complete hack.
Comment #67
boombatower CreditAttribution: boombatower commentedSince the security issue has been solved I went ahead and cleaned this up.
I abstracted the log read so it can be called without being forced to run queries. Eventually I could see having it clear the logs or something so that it can be called after each drupalGet|Post() if in verbose/debug mode so that the fatal error is require after the call that caused it, but for now we at least collect them on both sides.
This patch also read PHP XDebug output to provide line numbers and such, any message that does not match the format will simply be inserted as a whole. Updated the default line number and such (per talk with webchick).
And updated the static assertion method names per Dries' comment.
I have thoroughly tested this with both the web runner and run-tests.sh.
Comment #68
chx CreditAttribution: chx commentedJust comments need upgrading, one, around the pregs some examples would be good to see what's going on there (and maybe name the preg parts), two, refer why the simpletest user agent is valid like "function X already checked"
Comment #69
boombatower CreditAttribution: boombatower commentedProvided example next to regex with documentation and added a comment in common.inc to clarify how user-agent is validated per IRC review by chx.
EDIT: chx posted :)
Comment #70
boombatower CreditAttribution: boombatower commentedPer comment in IRC, chx indicated that he was functionally fine with this.
Comment #71
chx CreditAttribution: chx commentedyes this patch is fine!
Comment #72
boombatower CreditAttribution: boombatower commentedCorrect query sort order and add db_query_range() noticed by DamZ.
Comment #73
boombatower CreditAttribution: boombatower commentedLog during installation process.
Comment #74
boombatower CreditAttribution: boombatower commentedChange 4th argument to be more clear/simple and update documentation.
Comment #75
boombatower CreditAttribution: boombatower commentedIRC review from webchick:
Comment #76
webchickDamn. There is some ugly code in here that makes baby kittens cry. :\ Unfortunately, most of it was here before and wasn't introduced in this patch...
1. Please for the love of all that is holy, stick $operations[0][1][1] in a local variable called $test_id.
2. Please for the love of all that is holy, document what this bit of code is doing (both here and in run-tests.sh)
While I use and love XDebug, I think it's not the place for core to be catering to specific development tools. Please remove this.
Comment #77
boombatower CreditAttribution: boombatower commentedFresh off the press soaked in kitten tears.
Comment #78
chx CreditAttribution: chx commentedDo not hoid this one up but a followup really should add back xdebug support. It's quite expectable that ppl who want to use this will have xdebug on.
Comment #80
boombatower CreditAttribution: boombatower commentedRe-rolled and double checked.
@Dries: Do you agree with #78, if so I will roll a followup.
Comment #81
Dries CreditAttribution: Dries commentedI agree with #78. We can worry about xdebug after. I also agree with webchick that there is some ugly code, but we can clean that up later too (unless you want to do some of that now).
Comment #82
Dries CreditAttribution: Dries commentedCommitted to CVS HEAD. Thanks. Feel free to re-roll still.