Assertion fails after upgrade of lxml from 3.2.4 to 3.3.1

[Tobias Widén]

After the upgrade of lxml 3.2.4 to 3.3.1 one of our feature tests started failing with the following message:

#30 test_invalid_login (tests.feature.test_login_logout.TestLoginLogout) ... python2.7: Modules/gcmodule.c:326: visit_decref: Assertion `gc->gc.gc_refs != 0' failed.

(the test passed after downgrading back to 3.2.4)

Python : sys.version_info(major=2, minor=7, micro=5, releaselevel='final', serial=0)
lxml.etree : (3, 3, 1, 0)
libxml used : (2, 9, 0)
libxml compiled : (2, 9, 0)
libxslt used : (1, 1, 28)
libxslt compiled : (1, 1, 28)

[Tobias Widén (tobbetrollkarl)]

typo: unittest -> featuretest

[scoder (scoder)]

Could you provide any details about the workings of that test? And preferably shrink it down to some code snippet (with relevant data) that reproduces the error?

[scoder (scoder)]

A stack trace would also be helpful. gdb should be able to deliver that.

[Tobias Widén (tobbetrollkarl)]

The test is a Splinter testcase (http://splinter.cobrateam.info/)
The only import of lxml in our entire application is located inside Splinter. Splinter imports lxml in djangoclient.py and zopetestbrowser.py. Since we're not using Django it is more likely that it's something to do with the zopetestbrowser.

I can not reproduce the error in any other way than running that test at the moment. The test is an end to end test of the entire web application so it's hard to boil down. What it basically does is that it tries to log in with the wrong password and asserts that the page is displayed right.

    def test_invalid_login(self):
        username = 'foobar'
        password = 'asdf'

        self.open("/")

        self.assert_has_button('Log in')
        self.assert_has_no_link('Log out')

        self.login(username, password)

        message = self.b.find_by_css('.alert-danger')
        self.assertIn('Wrong username or password', message.text)

        self.assert_has_button('Log in')
        self.assert_has_no_link('Log out')

Since the error seems to occur during garbage collection, which is detached from the execution path of our application, getting a good stack trace is hard. This is a dump from faulthandler:

nosetests --no-path-adjustment --with-id --id-file=.noseids ./tests/feature ./tests/unit ./tests/integration
.............................E...............S...........python2.7: Modules/gcmodule.c:326: visit_decref: Assertion `gc->gc.gc_refs != 0' failed.
Fatal Python error: Aborted

Thread 0x00007f7433fff700:
  File "/home/jenkins/workspace/Web_Gerrit/env/lib/python2.7/site-packages/qpid_python-0.24-py2...", line 124 in run
  File "/usr/lib64/python2.7/threading.py", line 504 in run
  File "/usr/lib64/python2.7/threading.py", line 551 in __bootstrap_inner
  File "/usr/lib64/python2.7/threading.py", line 524 in __bootstrap

Thread 0x00007f7430dfa700:
  File "/usr/lib64/python2.7/threading.py", line 243 in wait
  File "/usr/lib64/python2.7/Queue.py", line 168 in get
  File "/home/jenkins/workspace/Web_Gerrit/env/lib/python2.7/site-packages/futures-2.1.6-py2.7....", line 71 in _worker
  File "/usr/lib64/python2.7/threading.py", line 504 in run
  File "/usr/lib64/python2.7/threading.py", line 551 in __bootstrap_inner
  File "/usr/lib64/python2.7/threading.py", line 524 in __bootstrap

Thread 0x00007f74317fb700:
  File "/usr/lib64/python2.7/threading.py", line 243 in wait
  File "/usr/lib64/python2.7/Queue.py", line 168 in get
  File "/home/jenkins/workspace/Web_Gerrit/env/lib/python2.7/site-packages/futures-2.1.6-py2.7....", line 71 in _worker
  File "/usr/lib64/python2.7/threading.py", line 504 in run
  File "/usr/lib64/python2.7/threading.py", line 551 in __bootstrap_inner
  File "/usr/lib64/python2.7/threading.py", line 524 in __bootstrap

Thread 0x00007f74321fc700:
  File "/usr/lib64/python2.7/threading.py", line 243 in wait
  File "/usr/lib64/python2.7/Queue.py", line 168 in get
  File "/home/jenkins/workspace/Web_Gerrit/env/lib/python2.7/site-packages/cassandra_driver-1.0...", line 1760 in run
  File "/usr/lib64/python2.7/threading.py", line 504 in run
  File "/usr/lib64/python2.7/threading.py", line 551 in __bootstrap_inner
...

[scoder (scoder)]

You could add a gc.collect() after each step of the test to see which one triggers the problem. That way, it should at least be possible to extract the HTML(?) page being processed and the problematic code section. Otherwise, given the massive amount of dependencies in the crashing system, it's nearly impossible to make even a guess what's going on here.

(Well, at least something seems to be keeping HTML trees in a reference cycle somewhere which are then cleaned up in cyclic garbage collection. But that's still very generic...)

[Tobias Widén (tobbetrollkarl)]

Adding a gc.collect() before self.login(username, password) causes the problem to disappear.

This is the log_in() method, where b is the test browser.

    def login(self, username, password):
        self.open('/login')
        self.b.fill('username', username)
        self.b.fill('password', password)
        self.b.find_by_name("submit-button").click()

[scoder (scoder)]

Most likely fixed as part of ticket #1287118.