search

open-craft / opencraft

OpenCraft - Instance Manager
https://ocim.opencraft.com
GNU Affero General Public License v3.0
55 stars 22 forks source link

[BB-1015] instance/tests/models/test_log_entry.py fails to fail when the locale is not found #395

Closed singuliere closed 5 years ago

singuliere commented 5 years ago

When there is no locale, the test shows a stack trace but does not fail as it should.

Steps to reproduce

What is expected:

The tests fail because the en_US.UTF-8 locale is not present

What happens instead

The tests succeed although they show a stack trace about the missing locale

...
test_log_publish (instance.tests.models.test_log_entry.LoggingTestCase) ... --- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3.5/logging/__init__.py", line 982, in emit
    stream.write(msg)
UnicodeEncodeError: 'ascii' codec can't encode characters in position 151-158: ordinal not in range(128)
Call stack:
  File "/opt/venv/bin/coverage", line 9, in <module>
    load_entry_point('coverage==4.2', 'console_scripts', 'coverage')()
  File "/opt/venv/lib/python3.5/site-packages/coverage/cmdline.py", line 753, in main
    status = CoverageScript().command_line(argv)
  File "/opt/venv/lib/python3.5/site-packages/coverage/cmdline.py", line 480, in command_line
    return self.do_run(options, args)
  File "/opt/venv/lib/python3.5/site-packages/coverage/cmdline.py", line 627, in do_run
    self.run_python_file(filename, args)
  File "/opt/venv/lib/python3.5/site-packages/coverage/execfile.py", line 177, in run_python_file
    exec(code, main_mod.__dict__)
  File "./manage.py", line 37, in <module>
    execute_from_command_line(sys.argv)
  File "/opt/venv/lib/python3.5/site-packages/django/core/management/__init__.py", line 367, in execute_from_command_line
    utility.execute()
  File "/opt/venv/lib/python3.5/site-packages/django/core/management/__init__.py", line 359, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/opt/venv/lib/python3.5/site-packages/django/core/management/commands/test.py", line 29, in run_from_argv
    super(Command, self).run_from_argv(argv)
  File "/opt/venv/lib/python3.5/site-packages/django/core/management/base.py", line 294, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/opt/venv/lib/python3.5/site-packages/django/core/management/base.py", line 345, in execute
    output = self.handle(*args, **options)
  File "/opt/venv/lib/python3.5/site-packages/django/core/management/commands/test.py", line 72, in handle
    failures = test_runner.run_tests(test_labels)
  File "/opt/venv/lib/python3.5/site-packages/django/test/runner.py", line 550, in run_tests
    result = self.run_suite(suite)
  File "/opt/venv/lib/python3.5/site-packages/django/test/runner.py", line 511, in run_suite
    ).run(suite)
  File "/usr/lib/python3.5/unittest/runner.py", line 176, in run
    test(result)
  File "/usr/lib/python3.5/unittest/suite.py", line 84, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib/python3.5/unittest/suite.py", line 122, in run
    test(result)
  File "/opt/venv/lib/python3.5/site-packages/django/test/testcases.py", line 213, in __call__
    super(SimpleTestCase, self).__call__(result)
  File "/usr/lib/python3.5/unittest/case.py", line 648, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib/python3.5/unittest/case.py", line 600, in run
    testMethod()
  File "/usr/lib/python3.5/unittest/mock.py", line 1157, in patched
    return func(*args, **keywargs)
  File "/home/singuliere/software/ocim/opencraft/instance/tests/models/test_log_entry.py", line 147, in test_log_publish
    self.server.logger.info('Text the client should also see, with unicode \xab\u03c4\u03b1\u0411\u042c\u2113\u03c3\xbb')
Message: 'server=11 (test-vm-name) | Text the client should also see, with unicode \xab\u03c4\u03b1\u0411\u042c\u2113\u03c3\xbb'
Arguments: ()
ok
antoviaque commented 5 years ago

@dupainaulevain Thanks for reporting this - can you make sure this is tracked in one of our Jira tickets, as part of our tech debt?

antoviaque commented 5 years ago

I've made the same confusion here between @singuliere and @dupainaulevain - sorry : )

@UmanShahzad I'll address this to you instead then - can you make sure this is tracked in one of our Jira tickets, as part of our tech debt?

UmanShahzad commented 5 years ago

@antoviaque cc @singuliere @dupainaulevain https://tasks.opencraft.com/browse/BB-1015

antoviaque commented 5 years ago

@UmanShahzad Thank you!

jcdyer commented 5 years ago

Point of clarification: The description says that the test "fails to fail," which suggests that the desired fix is for the test to fail properly, but under "what is expected" it shows all tests passing. What specific outcome should I be aiming for here?

dupainaulevain commented 5 years ago

The bug description is not good indeed. The problem to be fixed is that the tests fail to fail when there is a unicode problem.

singuliere commented 5 years ago

The descirption was updated, sorry about that.

jcdyer commented 5 years ago

I'm not sure whether this ought to be fixed. Inside python's logging module, the error occurs as part of the StreamHandler, and when the exception occurs, it is passed to a method called "handleError" which opens with the following docstring:

"""
Handle errors which occur during an emit() call.

This method should be called from handlers when an exception is
encountered during an emit() call. If raiseExceptions is false,
exceptions get silently ignored. This is what is mostly wanted
for a logging system - most users will not care about errors in
the logging system, they are more interested in application errors.
You could, however, replace this with a custom handler if you wish.
The record which was being processed is passed in to this method.
"""

and then goes on to print the exception to stderr.

So the tests pass because the logging system expressly indicates that its errors should be recorded, but should not propagate. We can, of course, override this behavior, as described in the docstring above. I'm just not sure if that's useful. We could also clean up the output with the following workarounds:

  1. Switching the test runner to pytest would also prevent the stacktrace from getting output on the command line.
  2. I think (though I haven't tested) that changing the log handler from StreamHandler to FileHandler would (I suspect) cause the output to be logged without regard to the LOCALE.

Postscript: This took some effort to diagnose, because the same locale issue that caused this error also causes pdb to fail when trying to printing out variables. I had to (1) replace the string literal with one containing ascii unicode escapes ('\xab\u03c4\u03b1\u0411\u042c\u2113\u03c3\xbb' instead of '«ταБЬℓσ»') to allow me to even step onto the line with that string in the debugger, and (2) assiduously avoid inspecting any variables that would try to show me the message string.

jcdyer commented 5 years ago

Note: I was not able to check out the above mentioned commit hash, but the problem could be duplicated on the current head of https://github.com/singuliere/opencraft/@docker-devstack (f0104d9043).

To do so I ran make devstack.shell (not make devstack.shell shell), and the checked for the current locale with env, only saw the LANG variable (set to en_US.utf-8 or something similar) and ran export LANG= with no value.

singuliere commented 5 years ago

Excellent sleuth work :-) The commit hash was probably discarded because is no longer part of a branch. I'll make sure to keep a dedicated branch around. I'll go ahead and close this issue: I agree it does not need fixing.