Random error

[NotSqrt]

Hi,

I am facing a random error in my tests, with django 1.8.12, coverage 4.0.3 and django_coverage_plugin 1.3 (and seemingly only on my CI server using ubuntu precise 32bit, not our developer machines using ubuntu >= 14.04 64bit):

django_coverage_plugin/plugin.py", line 170, in line_number_range
    assert frame.f_code.co_name == 'render'
AssertionError

(Side note, as it is an AssertionError exception, the test reports it as a failure, not an error)

It seems to be called from django/template/engine.py, line 168 (https://github.com/django/django/blob/1.8.12/django/template/engine.py#L168):

    def get_template(self, template_name, dirs=_dirs_undefined):
        """
        Returns a compiled Template object for the given template name,
        handling template inheritance recursively.
        """
        # ... removed for brevity
        if not hasattr(template, 'render'):  # <<-- fails here
            # template needs to be compiled
            template = Template(template, origin, template_name, engine=self)

This call comes from a fairly standard return render_to_string(template_name, context.flatten()) in a template tag.

I've managed to get a shell at the point of failure, and frame.f_code.co_name is indeed 'get_template'.

[NotSqrt]

It is random in the sense that it appears maybe 10% of the time.

[nedbat]

@NotSqrt hmm, strange. Are you using any concurrency libraries, like gevent, greenlets, or eventlets?

[NotSqrt]

I get this error when running tests with https://github.com/kmmbvnr/django-jenkins, on LiveServerTestCase tests calling selenium, so not directly concurrency libs, but definitely threads and subprocesses.

[nedbat]

OK, I'm not sure how well this will work, but let's try this experiment. In one of your tests, (anywhere, just some place that we can get the output, and we know that it's running in the same process as the occasional failures), add this code: "import pprint, sys; pprint.pprint(sys.modules)". If you need to, also add a failure like "1/0" to get the test runner to show you the output. Then we can see what libraries might be involved.

[NotSqrt]

Here is a list of the libraries extracted from import pprint, sys; pprint.pprint(sys.modules) in the function that raises the exception:

BaseHTTPServer
ConfigParser
Cookie
FixTk
HTMLParser
OpenSSL
PIL
Queue
SocketServer
StringIO
UserDict
UserList
_LWPCookieJar
_MozillaCookieJar
__builtin__
__future__
_abcoll
_ast
_bisect
_cffi_backend
_codecs
_collections
_csv
_ctypes
_curses
_cython_0_21_1
_cython_0_22
_elementtree
_functools
_hashlib
_heapq
_io
_json
_locale
_multiprocessing
_openssl
_random
_socket
_sre
_ssl
_strptime
_struct
_virtualenv_distutils
_warnings
_weakref
_weakrefset
abc
amqp
anyjson
appconf
argonauts
argparse
array
ast
asynchat
asyncore
atexit
backports
base64
billiard
binascii
bisect
bitarray
blessings
bootstrap3
braces
bz2
cPickle
cStringIO
calendar
celery
certifi
cffi
cgi
classytags
cmath
codecs
collections
colorsys
colour_runner
compat
concurrent
configurations
contextlib
cookielib
copy
copy_reg
coverage
crypt
cryptography
cssselect
cssutils
csv
ctypes
curses
datetime
dateutil
decimal
defusedxml
difflib
dis
distutils
django
django_countries
django_coverage_plugin
django_extensions
django_filters
django_jenkins
django_redis
django_statsd
email
encodings
encutils
enum
errno
exceptions
fcntl
fnmatch
formtools
fractions
ftplib
ftputil
funcsigs
functools
future_builtins
gc
genericpath
getopt
getpass
gettext
glob
googleapiclient
grp
gzip
hashlib
heapq
hijack
hiredis
hmac
html5lib
htmlentitydefs
httpagentparser
httplib
httplib2
imghdr
imp
importlib
inspect
io
ipaddress
ipware
itertools
jinja2
json
jwt
keyword
kombu
leaflet
linecache
locale
logging
logilab
lxml
markupbase
markupsafe
marshal
math
microsofttranslator
mimetools
mimetypes
mmap
mock
model_utils
msgpack
multiprocessing
multiupload
netrc
new
ntpath
numbers
numexpr
numpy
oauth2client
oauthlib
opcode
openid
operator
optparse
os
pandas
parler
pbr
pdfrw
pickle
pipeline
pkg_resources
pkgutil
platform
plistlib
polib
polymorphic
posix
posixpath
pprint
pptx
premailer
psutil
psycopg2
pty
pwd
pyasn1
pyexpat
pyftpdlib
pygments
pytz
quopri
random
re
redis
reportlab
requests
requests_oauthlib
resource
rest_framework
rest_framework_filters
rfc822
rosetta
scipy
sekizai
select
selenium
sendfile
sh
shlex
shutil
signal
simplejson
site
sitecustomize
six
smtplib
social
socket
sockjs
spwd
sre_compile
sre_constants
sre_parse
ssl
stat
statici18n
statsd
string
stringprep
strop
struct
subprocess
supervisor
swampdragon
sys
sysconfig
tarfile
tempfile
termios
textwrap
thread
threading
time
timeit
timezone_field
token
tokenize
traceback
tty
types
ujson
unicodedata
unittest
uritemplate
urllib
urllib2
urlparse
uu
uuid
warnings
watson
weakref
wsgiref
xlsxwriter
xml
zipfile
zipimport
zlib

[nedbat]

I don't see any smoking guns there. Selenium is notorious for unpredictability, but I don't see how it could produce assertions like that one.

[NotSqrt]

I tried to inspect the stack when entering the line_number_range method:

  File "/usr/lib/python2.7/threading.py", line 524, in __bootstrap
    self.__bootstrap_inner()
  File "/usr/lib/python2.7/threading.py", line 551, in __bootstrap_inner
    self.run()
  File "virtualenv/local/lib/python2.7/site-packages/django/test/testcases.py", line 1190, in run
    self.httpd.serve_forever()
  File "/usr/lib/python2.7/SocketServer.py", line 227, in serve_forever
    self._handle_request_noblock()
  File "/usr/lib/python2.7/SocketServer.py", line 284, in _handle_request_noblock
    self.process_request(request, client_address)
  File "/usr/lib/python2.7/SocketServer.py", line 310, in process_request
    self.finish_request(request, client_address)
  File "/usr/lib/python2.7/SocketServer.py", line 323, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "virtualenv/local/lib/python2.7/site-packages/django/core/servers/basehttp.py", line 102, in __init__
    super(WSGIRequestHandler, self).__init__(*args, **kwargs)
  File "/usr/lib/python2.7/SocketServer.py", line 638, in __init__
    self.handle()
  File "virtualenv/local/lib/python2.7/site-packages/django/core/servers/basehttp.py", line 182, in handle
    handler.run(self.server.get_app())
  File "/usr/lib/python2.7/wsgiref/handlers.py", line 85, in run
    self.result = application(self.environ, self.start_response)
  File "virtualenv/local/lib/python2.7/site-packages/django/contrib/staticfiles/handlers.py", line 63, in __call__
    return self.application(environ, start_response)
  File "virtualenv/local/lib/python2.7/site-packages/django/test/testcases.py", line 1107, in __call__
    return self.application(environ, start_response)
  File "virtualenv/local/lib/python2.7/site-packages/django/core/handlers/wsgi.py", line 189, in __call__
    response = self.get_response(request)
  File "virtualenv/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 164, in get_response
    response = response.render()
  File "virtualenv/local/lib/python2.7/site-packages/django/template/response.py", line 158, in render
    self.content = self.rendered_content
  File "virtualenv/local/lib/python2.7/site-packages/django/template/response.py", line 135, in rendered_content
    content = template.render(context, self._request)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/backends/django.py", line 74, in render
    return self.template.render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/base.py", line 210, in render
    return self._render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/test/utils.py", line 96, in instrumented_test_render
    return self.nodelist.render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/base.py", line 905, in render
    bit = self.render_node(node, context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/debug.py", line 79, in render_node
    return node.render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/loader_tags.py", line 135, in render
    return compiled_parent._render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/test/utils.py", line 96, in instrumented_test_render
    return self.nodelist.render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/base.py", line 905, in render
    bit = self.render_node(node, context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/debug.py", line 79, in render_node
    return node.render(context)
  File "virtualenv/local/lib/python2.7/site-packages/classytags/core.py", line 146, in render
    return self.render_tag(context, **kwargs)
  File "virtualenv/local/lib/python2.7/site-packages/sekizai/templatetags/sekizai_tags.py", line 83, in render_tag
    rendered_contents = nodelist.render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/base.py", line 905, in render
    bit = self.render_node(node, context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/debug.py", line 79, in render_node
    return node.render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/defaulttags.py", line 329, in render
    return nodelist.render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/base.py", line 905, in render
    bit = self.render_node(node, context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/debug.py", line 79, in render_node
    return node.render(context)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/loader_tags.py", line 151, in render
    template = context.template.engine.get_template(template)
  File "virtualenv/local/lib/python2.7/site-packages/django/template/engine.py", line 170, in get_template
    if not hasattr(template, 'render'):

It is clearly in the LiveServerThread, not the main thread.

It is not always the same template that makes it fail.

In line_number_range, the template instance is in frame.f_locals['template'], but it has no loaded source, so it can't be used in position_for_node.

Do you want me to look in a specific direction ?
I was unable to simplify and reproduce the bug in a clean django project.

[hz]

@NotSqrt, I noticed that StringIO shares the same memory between the celery worker processes. It generated some corrupted contents in my project. Would it be the root cause for your case?

[NotSqrt]

@hz It's hard to tell..