Support from Acquia helps fund testing for Drupal Acquia logo

Comments

xjm’s picture

Setting postponed for now. I think I saw a different failure in the statistics module the other day but I've not tracked it down yet. If it turns out the test is bugged then we can move this to statistics.module.

jthorson’s picture

Simular statistics test failure seen on http://drupal.org/node/1290710 (though you may not see it, since it's being retested) ... appears to be a intermittent problem with that particular test.

penyaskito’s picture

xjm’s picture

Title: StatisticsLoggingTestCase->testLogging() may be unstable » StatisticsLoggingTestCase->testLogging() is unstable
Project: Drupal.org Testbots » Drupal core
Version: » 8.x-dev
Component: unexplained test failure » statistics.module
Priority: Normal » Major
Status: Postponed » Active

So pretty clear this test needs fixing. Moving to statistics.module and bumping to major, because it's really annoying to have one out of every five or ten tests fail randomly. :P

xjm’s picture

The last line here is the one that fails (line 139 of statistics.test):

    // Create a path longer than 255 characters.                                
    $long_path = $this->randomString(256);

    // Test that the long path is properly truncated when logged.               
    $this->drupalGet($long_path);
    $log = db_query('SELECT * FROM {accesslog}')->fetchAll(PDO::FETCH_ASSOC);
    $this->assertTrue(is_array($log) && count($log) == 8, 'Page request was logged for a path over 255 characters.');
    $this->assertEqual($log[7]['path'], truncate_utf8($long_path, 255));

First value from the original post above:
'o;;\\Vo `!V,(">O/|^zckPbK&ZNs1S=7"F)|q%Hdx5U47j||s&<G2]0Mx|A $\\D[q9~=!zzm$#{dS\\*=%_G3pHI]DV\\V1J|[9mmos[&x*Z/d,RVBeLE\\(va@C@Yg\\3z~/B$j+1Y"U<`\\$H/A@<<1+Df(M(!RC=6QHrF4BPNf^pq7ZGR<zwdac~cE-7o6v?{wH|T1(eDn6u3\\DZz=FGA/Ehkrr[g!/*lj6:CMxl1i_9.<mk? #3N4LI}/Bzh7\\!J'

Second value:
'/o;;\\Vo `!V,(">O/|^zckPbK&ZNs1S=7"F)|q%Hdx5U47j||s&<G2]0Mx|A $\\D[q9~=!zzm$#{dS\\*=%_G3pHI]DV\\V1J|[9mmos[&x*Z/d,RVBeLE\\(va@C@Yg\\3z~/B$j+1Y"U<`\\$H/A@<<1+Df(M(!RC=6QHrF4BPNf^pq7ZGR<zwdac~cE-7o6v?{wH|T1(eDn6u3\\DZz=FGA/Ehkrr[g!/*lj6:CMxl1i_9.<mk? #3N4LI}/Bzh7\\!'

I imagine maybe these aren't valid paths, so that would explain the failure?

Edit: The logged path (second value) has a slash added at the beginning, and the truncated original path (first value) ends in a J that gets bumped off when the slash is added. So something in drupalGet() is causing that slash to be prepended.

Edit 2: The path contains :, ?, and #, which could cause url() to alter it.

xjm’s picture

Note that this path, crazy as it is, appears to be a perfectly valid URL alias. At least, it does not fail validation.

xjm’s picture

Aha. I was mistaken before. The second value is actually the original, generated path, which happened to start with a / -- which, naturally, gets stripped. That would explain it. So, maybe we should always add one alphanumeric character to the beginning and end of the path to ensure it doesn't have leading or trailing slashes.

I don't know if that's why the other tests failed, though. I can't imagine the initial character is a slash that often. A 1 in 128 chance or so?

xjm’s picture

Status: Active » Needs review
FileSize
954 bytes
xjm’s picture

catch’s picture

Why not just a longer $this->randomName() instead of the wrapping?

Nice work tracking this down!

xjm’s picture

#10: Well, I was thinking that we should still test with all those non-alphanumeric characters, since they are valid path characters. I could go either way, though.

What would be totally awesome would be for someone to run this particular test case a few thousand times both with and without the patch to make sure the patch fixes the test. I'm assuming drush has testing integration one could use to script it. Edit: If it doesn't, then we should probably do as catch suggests, and additionally create a followup issue to test our path handling with non-alphanumeric characters.

xjm’s picture

FileSize
1.89 KB

Alright, actually, there are other weird failures too when I run the test repeatedly. E.g., the path gets set to NULL:

Statistics logging tests 31 passes, 2 fails, 1 exception, and 7 debug[error]
messages
Test StatisticsLoggingTestCase->testLogging() failed: Page request   [error]
was logged for a path over 255 characters.
Test StatisticsLoggingTestCase->testLogging() failed: Undefined      [error]
offset: 7
Test StatisticsLoggingTestCase->testLogging() failed: Value NULL is  [error]
equal to value
&#039;{\&#039;mzGNdkp17{@z!&quot;}jFX&lt;~[JS,Z&amp;zEdhxop6Vj-0N$PF)HBw5O&gt;&gt;Q$uY2&lt;=:iLO,,=oI3&amp;)r_Cg2.jx\\)6=L7Eh?nr*bMdkPp3;~\\hky5PD5&gt;+*deX2$H{igC{!0svT#}eDUE\&#039;4`W?iFvDAL;m[9n\\kXe@f.K
nF!jyNL9ui9=5FyO.wHzEb1wU,H_\\ =h6a+ce{BLjv&lt;gARC*[+8**4(W&lt;uN9
kzhhQJkudkmidbD4M]\\}DikvErAxS_I#HpKU&#039;.

So here's a patch that just uses randomName() as suggested in #10.

xjm’s picture

FileSize
616 bytes

Er. Without random hunks from other stuff.

xjm’s picture

Note that #12 actually may have been a problem with my local environment. Drupal was throwing a 403 instead of a 404 for any path string over 255 characters unless it included a fragment or query string, which meant that NULL was logged instead of the requested path. I can't reproduce that now, though.

xjm’s picture

Alright, my script just finished running #13 1000 times with no failures. So, I think/hope that is the right fix.

xjm’s picture

Issue tags: +Needs backport to D7

Yeah, this test is in D7 too.

bfroehle’s picture

Status: Needs review » Reviewed & tested by the community

Yes, using randomName() here is the easiest way to remove these spurious errors.

webchick’s picture

Status: Reviewed & tested by the community » Fixed

Great. Committed and pushed to 8.x and 7.x. Yay for fewer random, frustrating fails, and yay for killing a major bug. :)

David_Rothstein’s picture

Priority: Major » Normal
Status: Fixed » Needs work

Note that #12 actually may have been a problem with my local environment. Drupal was throwing a 403 instead of a 404 for any path string over 255 characters unless it included a fragment or query string, which meant that NULL was logged instead of the requested path. I can't reproduce that now, though.

I'm seeing similar failures running these tests locally. The 403 I see comes from Apache, not Drupal, though; it is simply refusing to serve a path that's as long as the ones used in this test. It may be a server configuration issue, but if so, it's probably a pretty common one.

Interestingly, I only see this when running the tests in Drupal 7, not Drupal 8. The difference is that for some reason, the tests in Drupal 7 wind up running with clean URLs on, but in Drupal 8 they run with clean URLs off. Not sure if this change in Simpletest behavior is intentional or a bug, but either way, it causes the tests to fail for me locally only in Drupal 7 because this:

http://drupal.dev/eHqdapXZmE............

makes Apache unhappy, but this:

http://drupal.dev/?q=eHqdapXZmE............

doesn't.

Reopening this but at lower priority (since the testbot itself apparently isn't affected).

sanduhrs’s picture

I can confirm the behavior described in #22 on Ubuntu 11.04 Server (ext4).
Perhaps the issue described in http://serverfault.com/questions/120397/max-length-of-url-257-characters... is the reason for it?

xjm’s picture

Title: StatisticsLoggingTestCase->testLogging() is unstable » StatisticsLoggingTestCase->testLogging() fails with clean URLs in some environments
Dave Reid’s picture

Priority: Normal » Major

I can confirm this as well.

scor’s picture

able to reproduce this with latest core (right before 7.13) on two machines:
- testbot instance: fresh debian that rfay built today PHP 5.3.3-7+squeeze6 with Suhosin-Patch (cli) (built: Jan 31 2012 10:56:51)
- my localhost is MAMP with PHP 5.3.6 (cli) (built: May 25 2011 20:42:15).

tested the cli via php ./scripts/run-tests.sh --verbose --url http://localhost/d7-dev/ --color --class StatisticsLoggingTestCase and on the web ui on localhost.

xjm’s picture

So, if some hosts don't support paths longer than 255 characters, then why are we doing so? There's nothing functionally wrong with this test. Do we need to change how we fixed #1180642: PDOException in statistics_exit() when path longer than 255 characters?

webchick’s picture

Priority: Major » Normal

Why is this major? Annoying, yes, but this is an edge case not worth holding up D8 features for.

xjm’s picture

Issue tags: +Random test failure
scor’s picture

Version: 8.x-dev » 7.x-dev
Status: Needs work » Needs review
FileSize
1.11 KB

Running the security patches on the private testbot today reminded me of this annoying issue again, so I looked into it some more. The testbed initialized by PIFR has clean urls disabled which is why public testbots don't encounter this issue, that's in line with what David descibed in #22.

When clean urls are enabled, Apache will try to match the path on the filesystem, and if the filename is > 255 it will 403. All we have to do is to break down the path with a '/'. This is actually already fixed in D8, the patch attached backports a part of #1183208: Remove variable_get('clean_url') and switch to index.php/path pattern for dirty URL support to D7.

xjm’s picture

Status: Needs review » Reviewed & tested by the community

Awesome @scor. The fix makes sense, still provides the coverage intended, and is well-documented.

webchick’s picture

Status: Reviewed & tested by the community » Fixed

Confirmed that this is the same fix as in 8.x. Committed and pushed to 7.x. Thanks!

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