Suppress Java noise on Windows/AppVeyor

[khaeru]

Closes #229.

See jpype-project/jpype#561. To summarize:

• pytest has a core plugin that enables Python's faulthandler module by default.
• Something in Java causes signals to be emitted, causing these tracebacks to be printed by faulthandler. However, per this comment, these are intentional, and not fatal in Java—so the messages are spurious and not related to any error/failure.

This PR

• Addresses the issue by adding -p no:faulthandler to the pytest options.
• Also simplifies ixmp.backend.jdbc.start_jvm, allowing JPype to construct the classpath argument.

How to review

• View the AppVeyor build logs for the latest commit on this branch and confirm that the messages described in JDBCBackend is noisy on Windows #229 do not appear.
• Run on a Windows machine and confirm again that the messages do not appear.

PR checklist

• Tests added. N/A
• Documentation added. N/A, CI/internal changes only.
• Release notes updated. N/A, CI/internal changes only.

[khaeru]

Observations:

• f3f058e shows:

  ---------------------------- Captured stdout setup ----------------------------
  jpype.getDefaultJVMPath(): ['C:\\Miniconda36-x64\\Library\\bin\\server\\jvm.dll']
  JAVA_HOME: C:\Miniconda36-x64\Library
  

• 237c93e, which is identical except for an assertion, still shows the noisy “Windows fatal exception: access violation” messages: https://ci.appveyor.com/project/iiasa/ixmp/builds/29976460 / https://ci.appveyor.com/project/iiasa/ixmp/builds/29976460/job/0m84ruggo2jrndlb

Conclusion: forcing the use of the Anaconda-installed OpenJDK doesn't make these messages go away.

[khaeru]

In 09dde55, only start_jvm() is called, and JAVA_CLASSES is emptied so that no Java class is imported. The messages still appear.

[khaeru]

@GamzeUnlu95 would you please:

1. Clone this branch,
2. Remove the .dll, .so, and .dynlib files from the ixmp/lib/ directory.
3. Run pytest -k test_jvm_warn.
4. Re-add the files, one-by-one, repeating Update solve #3 each time?

The intent: removing some of the files may break the code in other ways, but we may identify if the messages are associated with a single file.

Please send me messages in Slack with the different exception messages you get, instead of posting here.

@zikolach I recognize this is very crude. If you have an alternate suggestion for a debugging procedure, please do share…

[GamzeUnlu95]

No matter which .dll/.so/.dynlib files are there or even none of them are there, the same message appears: tests\backend\test_jdbc.py Windows fatal exception: access violation.

[khaeru]

Hi @francescolovat @GamzeUnlu95 —would you please test the latest commit on this branch and see if pytest is now quiet on your computers?

@zikolach I am requesting your review of the changes; please see the linked issue on JPype for more description.

[francescolovat]

Hi @khaeru ,

thanks for the improvements.

I've ran the command both with and without deleting the files .dll, .so, and .dynlib in /lib, same result:

(base) C:\Users\lovat\Documents\GitHub\khaeru\ixmp>pytest -k test_jvm_warn
================================================= test session starts =================================================
platform win32 -- Python 3.7.3, pytest-5.2.1, py-1.8.0, pluggy-0.13.0
ixmp config: {'platform': {'default': 'local', 'local': {'class': 'jdbc', 'driver': 'hsqldb'}}}
rootdir: C:\Users\lovat\Documents\GitHub\khaeru\ixmp, inifile: setup.cfg, testpaths: tests
plugins: arraydiff-0.3, cov-2.8.1, doctestplus-0.4.0, openfiles-0.4.0, remotedata-0.3.1
collected 128 items / 127 deselected / 1 selected

tests\backend\test_jdbc.py .                                                                                     [100%]Coverage.py warning: No data was collected. (no-data-collected)


----------- coverage: platform win32, python 3.7.3-final-0 -----------
Name                             Stmts   Miss  Cover   Missing
--------------------------------------------------------------
ixmp\__init__.py                    12     12     0%   1-22
ixmp\_config.py                    117    117     0%   1-293
ixmp\backend\__init__.py             2      2     0%   2-16
ixmp\backend\base.py               108    108     0%   1-874
ixmp\backend\jdbc.py               388    388     0%   1-839
ixmp\cli.py                         70     70     0%   1-114
ixmp\core.py                       405    405     0%   1-1425
ixmp\model\__init__.py               6      6     0%   3-11
ixmp\model\base.py                   1      1     0%   1
ixmp\model\gams.py                  37     37     0%   1-136
ixmp\reporting\__init__.py         224    224     0%   21-700
ixmp\reporting\attrseries.py        79     79     0%   1-137
ixmp\reporting\computations.py      71     71     0%   5-207
ixmp\reporting\describe.py          33     33     0%   1-73
ixmp\reporting\key.py               59     59     0%   1-152
ixmp\reporting\utils.py            116    116     0%   1-322
ixmp\testing.py                    146    146     0%   12-387
ixmp\utils.py                       98     98     0%   1-197
--------------------------------------------------------------
TOTAL                             1972   1972     0%
Coverage XML written to file coverage.xml


========================================== 1 passed, 127 deselected in 1.15s ==========================================

(base) C:\Users\lovat\Documents\GitHub\khaeru\ixmp>

I don't know if warning: No data was collected. (no-data-collected) leads to coverage 0% though...

[zikolach]

@khaeru so main conclusion is that those messages started to appear after release of pytest 5.0.0 (2019-06-28), correct?
In particular:

#5440: The faulthandler standard library module is now enabled by default to help users diagnose crashes in C modules.

This functionality was provided by integrating the external pytest-faulthandler plugin into the core, so users should remove that plugin from their requirements if used.

For more information see the docs: https://docs.pytest.org/en/latest/usage.html#fault-handler

Would it make sense to try downgrading to pytest prior to version 5.0 to check if that was the case?

I tried to find anything specifically related in jdk 11 docs. Should we also give a try running jvm with option -Xrs (if that makes any sense, maybe it can give more information what leads to thread crashing/logging)?

[khaeru]

Would it make sense to try downgrading to pytest prior to version 5.0 to check if that was the case?

I tried to find anything specifically related in jdk 11 docs. Should we also give a try running jvm with option -Xrs (if that makes any sense, maybe it can give more information what leads to thread crashing/logging)?

Neither of these things are necessary. See this comment in the linked JPype issue, particularly:

As noted in the developers guide Java uses Access Exceptions for its own purposes. The first thing that it does when starting up the JVM is triggering an exception to check if the hook is installed properly. But it appears possible that pytest installs its own hooks which interfere with the Java hooks. The reason nothing happens is that it goes to pytest, dumps the exception and then transfers to the regular Java handler than suppresses the whole thing. That would explain how a fatal error has no effect.

In other words, this signal is something completely harmless that Java (not ixmp_source) always does, and which JPype does not currently hide from Python/faulthandler. So Python/faulthandler printing the messages does not indicate any failure in ixmp_source, JPype, or Java.

I already confirmed, through several of the debugging commits above, that disabling the pytest's faulthandler plugin solves the issue (again: the issue is just that the messages are noisy; not that they indicate something going wrong underneath). The change in pytest 5.0 was to turn this on by default. The fix on this branch is to disable it when pytest is run for ixmp. Per the updated description of the PR, see the build logs to confirm that the messages do not appear.