apache2 run-test-suite fails frequently in autopkgtest in groovy/armhf

Bug #1890302 reported by Balint Reczey
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Apache2 Web Server
Incomplete
Medium
apache2 (Ubuntu)
Fix Released
High
Bryce Harrington

Bug Description

https://objectstorage.prodstack4-5.canonical.com/v1/AUTH_77e2ada1e7a84929a74ba3b87153c0ac/autopkgtest-groovy/groovy/armhf/a/apache2/20200803_224820_a4672@/log.gz
...
# Failed test 17 in t/apache/expr_string.t at line 87
t/apache/expr_string.t ..............
Failed 1/29 subtests
...

Related branches

Revision history for this message
Bryce Harrington (bryce) wrote :

Some of the other test cases appear to randomly fail, in addition to #17:

t/apache/expr.t ..................... ok
# Failed test 11 in t/apache/expr_string.t at line 87
# Failed test 14 in t/apache/expr_string.t at line 101 fail #3
# Failed test 17 in t/apache/expr_string.t at line 101 fail #4
# Failed test 20 in t/apache/expr_string.t at line 101 fail #5
# Failed test 23 in t/apache/expr_string.t at line 101 fail #6
# Failed test 26 in t/apache/expr_string.t at line 101 fail #7
# Failed test 29 in t/apache/expr_string.t at line 101 fail #8
t/apache/expr_string.t ..............
Failed 7/29 subtests

t/apache/expr.t ..................... ok
# Failed test 14 in t/apache/expr_string.t at line 87
# Failed test 17 in t/apache/expr_string.t at line 87 fail #2
# Failed test 20 in t/apache/expr_string.t at line 101 fail #4
# Failed test 23 in t/apache/expr_string.t at line 101 fail #5
# Failed test 26 in t/apache/expr_string.t at line 87 fail #3
t/apache/expr_string.t ..............
Failed 5/29 subtests
t/apache/getfile.t .................. ok

Revision history for this message
Bryce Harrington (bryce) wrote :

Looking at the code for this test, it feels familiar. I think Andreas and I investigated a similar issue some months ago. I seem to recall we suspected apache was either segfaulting or timing out. I don't recall if that was on armhf but it may have been.

Changed in apache2 (Ubuntu):
importance: Undecided → High
status: New → Triaged
Revision history for this message
Bryce Harrington (bryce) wrote :

What the test in expr_string.t is doing is to craft .htaccess files with invalid expressions like 'foo' or '}' and then perform GET() requests against the local apache server, pulling the url '/apache/expr/index.html'. It then examines the error.log's info debug lines to check if what got logged is sensible.

Revision history for this message
Bryce Harrington (bryce) wrote :

Upstream appears to have hit the error before as well:

http://mail-archives.apache.org/mod_mbox/httpd-dev/202001.mbox/%<email address hidden>%3E
http://mail-archives.apache.org/mod_mbox/httpd-dev/202001.mbox/%3C20200113145056.GA12523%40redhat.com%3E
https://travis-ci.org/github/apache/httpd/jobs/633442262

"""
I'm guessing this is some kind of timing issue in the test case, which
tries to read an error_log entry immediately after the request which
generates it. I've added a sleep which will maybe mitigate this -
http://svn.apache.org/r1872705 so let's see how this one goes
"""

Revision history for this message
Bryce Harrington (bryce) wrote :

Checking with Andreas, he had created a branch with additional verbosity:
https://code.launchpad.net/~ahasenack/ubuntu/+source/apache2/+git/apache2

However, with the debug statements, the issue didn't reproduce.

I guess that fits with upstream's hypothesis that there is a race condition reading the error log.

What upstream tested was adding a little sleep:
http://svn.apache.org/viewvc/httpd/test/framework/trunk/t/apache/expr_string.t?r1=1872705&r2=1872704&pathrev=1872705&view=patch

We can cherry-pick that and see if it resolves it for us as well. The test case is in the debian/ tree, so this shouldn't be too invasive.

Changed in apache2 (Ubuntu):
assignee: nobody → Bryce Harrington (bryce)
Revision history for this message
In , Bryce Harrington (bryce) wrote :

Ubuntu's CI has seen an irregularly recurring test failure:

t/apache/etags.t .................... ok
t/apache/expr.t ..................... ok
# Failed test 17 in t/apache/expr_string.t at line 87
t/apache/expr_string.t ..............
Failed 1/29 subtests
t/apache/getfile.t .................. ok

https://bugs.launchpad.net/ubuntu/+source/apache2/+bug/1890302
https://autopkgtest.ubuntu.com/packages/a/apache2/groovy/armhf

We have not been able to reproduce the issue on local hardware, only in CI. We had attempted to add debug info to help isolate the cause, but with it added the test case always passed.

It looks like Apache2 upstream also noticed this failure in the Apache2 CI:

http://mail-archives.apache.org/mod_mbox/httpd-dev/202001.mbox/%<email address hidden>%3E
http://mail-archives.apache.org/mod_mbox/httpd-dev/202001.mbox/%3C20200113145056.GA12523%40redhat.com%3E
https://travis-ci.org/github/apache/httpd/jobs/633442262

This thread speculates it's a timing issue reading the error log too quickly, and suggests adding a usleep() might work around the problem. I've applied this change to Ubuntu to see if it passes our CI.

Revision history for this message
In , Bryce Harrington (bryce) wrote :

Btw, we're seeing this on the armhf architecture, but the apache mailing list discussion suggests its not arch-specific.

Changed in apache2:
importance: Unknown → Medium
status: Unknown → Confirmed
Revision history for this message
In , Jorton-9 (jorton-9) wrote :

What revision of the perl framework are you seeing that fail with?

I don't think we have seen this fail in Travis since applying r1844947

Revision history for this message
In , Jorton-9 (jorton-9) wrote :

No idea where that rev number came from. Since r1872705 I meant

Bryce Harrington (bryce)
Changed in apache2 (Ubuntu):
status: Triaged → Fix Committed
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package apache2 - 2.4.43-1ubuntu2

---------------
apache2 (2.4.43-1ubuntu2) groovy; urgency=medium

  * d/p/t/apache/expr_string.t: Avoid test suite failure due to timing
    issue reading error log too quickly after request, by adding a sleep.
    (LP: #1890302)

 -- Bryce Harrington <email address hidden> Wed, 05 Aug 2020 12:44:59 -0700

Changed in apache2 (Ubuntu):
status: Fix Committed → Fix Released
Changed in apache2:
status: Confirmed → Incomplete
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.