Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

JDBCBackend is noisy on Windows #229

Closed
khaeru opened this issue Nov 30, 2019 · 3 comments · Fixed by #247
Closed

JDBCBackend is noisy on Windows #229

khaeru opened this issue Nov 30, 2019 · 3 comments · Fixed by #247
Assignees
@zikolach @khaeru
Labels
bug
Milestone
2.0

Comments

@khaeru
Copy link
Member

khaeru commented Nov 30, 2019 •
edited
Loading

AppVeyor test logs such as this one (also manual pytest runs I've seen on e.g. @GamzeUnlu95's machine) spit out many copies of lines like:

[00:07:48] Windows fatal exception: access violation
[00:07:48] 
[00:07:48] Current thread 0x00000b18 (most recent call first):
[00:07:48]   File "c:\projects\ixmp\ixmp\backend\jdbc.py", line 320 in commit
[00:07:48]   File "c:\projects\ixmp\ixmp\backend\base.py", line 25 in __call__
[00:07:48]   File "c:\projects\ixmp\ixmp\core.py", line 358 in _backend
[00:07:48]   File "c:\projects\ixmp\ixmp\core.py", line 383 in commit
[00:07:48]   File "c:\projects\ixmp\ixmp\testing.py", line 248 in make_dantzig
[00:07:48]   File "C:\projects\ixmp\tests\test_model.py", line 11 in test_GAMSModel
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\python.py", line 166 in pytest_pyfunc_call
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\callers.py", line 187 in _multicall
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 81 in <lambda>
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 87 in _hookexec
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\hooks.py", line 289 in __call__
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\python.py", line 1435 in runtest
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\runner.py", line 131 in pytest_runtest_call
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\callers.py", line 187 in _multicall
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 81 in <lambda>
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 87 in _hookexec
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\hooks.py", line 289 in __call__
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\runner.py", line 207 in <lambda>
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\runner.py", line 234 in from_call
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\runner.py", line 207 in call_runtest_hook
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\runner.py", line 182 in call_and_report
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\runner.py", line 96 in runtestprotocol
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\runner.py", line 81 in pytest_runtest_protocol
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\callers.py", line 187 in _multicall
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 81 in <lambda>
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 87 in _hookexec
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\hooks.py", line 289 in __call__
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\main.py", line 270 in pytest_runtestloop
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\callers.py", line 187 in _multicall
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 81 in <lambda>
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 87 in _hookexec
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\hooks.py", line 289 in __call__
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\main.py", line 246 in _main
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\main.py", line 196 in wrap_session
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\main.py", line 239 in pytest_cmdline_main
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\callers.py", line 187 in _multicall
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 81 in <lambda>
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\manager.py", line 87 in _hookexec
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\pluggy\hooks.py", line 289 in __call__
[00:07:48]   File "C:\Miniconda36-x64\lib\site-packages\_pytest\config\__init__.py", line 92 in main
[00:07:48]   File "C:\Miniconda36-x64\Scripts\pytest-script.py", line 10 in <module>

Note the first lines: this occurs in JDBCBackend.commit:

ixmp/ixmp/backend/jdbc.py

Lines 320 to 323 in e6b3c0d

def commit(self, ts, comment):
self.jindex[ts].commit(comment)
if ts.version == 0:
ts.version = self.jindex[ts].getVersion()

…which in turn is calling the Java method TimeSeries.commit: https://github.com/iiasa/ixmp_source/blob/e534e3c23fa100933429f9369d26a7e463c94aaa/src/main/java/at/ac/iiasa/ixmp/objects/TimeSeries.java#L906-L971

It seems that the code still functions as intended, i.e. the tests all pass. The noisy warnings are simply an annoyance.
@khaeru khaeru added the bug label Nov 30, 2019
@khaeru
Copy link
Member Author

khaeru commented Nov 30, 2019

@zikolach do you know what might cause Java to issue these messages on Windows?

@khaeru khaeru added this to the 2.0 milestone Jan 8, 2020
@khaeru khaeru mentioned this issue Jan 8, 2020
Merged
3 tasks
@khaeru khaeru changed the title JDBCBackend.commit() is noisy on Windows JDBCBackend is noisy on Windows Jan 9, 2020
@khaeru
Copy link
Member Author

khaeru commented Jan 9, 2020

On closer inspection, these happen in multiple different methods—not just commit. See below. I do not know what the common denominator is between these.

Current thread 0x00000a80 (most recent call first):
  File "C:\Miniconda36-x64\lib\site-packages\jpype\_jobject.py", line 95 in __init__
  File "c:\projects\ixmp\ixmp\backend\jdbc.py", line 209 in __init__
  File "c:\projects\ixmp\ixmp\core.py", line 122 in __init__
  File "c:\projects\ixmp\ixmp\testing.py", line 108 in create_test_mp

Current thread 0x00000a80 (most recent call first):
  File "c:\projects\ixmp\ixmp\backend\jdbc.py", line 675 in clear_solution
  File "c:\projects\ixmp\ixmp\backend\base.py", line 25 in __call__
  File "c:\projects\ixmp\ixmp\core.py", line 358 in _backend
  File "c:\projects\ixmp\ixmp\core.py", line 1267 in remove_solution

Current thread 0x00000a80 (most recent call first):
  File "c:\projects\ixmp\ixmp\backend\jdbc.py", line 334 in commit
  File "c:\projects\ixmp\ixmp\backend\base.py", line 25 in __call__
  File "c:\projects\ixmp\ixmp\core.py", line 358 in _backend
  File "c:\projects\ixmp\ixmp\core.py", line 383 in commit

Current thread 0x00000a80 (most recent call first):
  File "c:\projects\ixmp\ixmp\backend\jdbc.py", line 467 in clone
  File "c:\projects\ixmp\ixmp\backend\base.py", line 25 in __call__
  File "c:\projects\ixmp\ixmp\core.py", line 358 in _backend
  File "c:\projects\ixmp\ixmp\core.py", line 1238 in clone

Current thread 0x00000a80 (most recent call first):
  File "c:\projects\ixmp\ixmp\backend\jdbc.py", line 257 in get_auth
  File "c:\projects\ixmp\ixmp\core.py", line 291 in check_access
  File "C:\projects\ixmp\tests\test_access.py", line 84 in test_check_single_model_access

Current thread 0x00000a80 (most recent call first):
  File "c:\projects\ixmp\ixmp\backend\jdbc.py", line 313 in get
  File "c:\projects\ixmp\ixmp\backend\base.py", line 25 in __call__
  File "c:\projects\ixmp\ixmp\core.py", line 358 in _backend
  File "c:\projects\ixmp\ixmp\core.py", line 611 in __init__
  File "C:\projects\ixmp\tests\test_core.py", line 33 in test_default_version

Current thread 0x00000a80 (most recent call first):
  File "C:\Miniconda36-x64\lib\site-packages\jpype\_core.py", line 219 in startJVM
  File "c:\projects\ixmp\ixmp\backend\jdbc.py", line 785 in start_jvm
  File "c:\projects\ixmp\ixmp\backend\jdbc.py", line 193 in __init__
  File "c:\projects\ixmp\ixmp\core.py", line 122 in __init__
  File "C:\projects\ixmp\tests\test_access.py", line 81 in test_check_single_model_access

@khaeru
Copy link
Member Author

khaeru commented Jan 10, 2020

  1. Searching shows that these “access violation” issues are related to Data Execution Protection (DEP) on Windows. Compiled code that is executed must be marked as such; if not the error occurs.
  2. The messages occur on the earliest build under the iiasa/message_ix project on AppVeyor https://ci.appveyor.com/project/iiasa/message-ix/builds/28426581. I unfortunately asked @gidden and @danielhuppmann to delete AppVeyor projects also named "message_ix" under their respective accounts, so older builds (particularly, those during/before Add Backend, JDBCBackend, Model, GAMSModel classes #182) are no longer available. Thus, I can't bisect to determine when this began.
  3. Some of the files in the ixmp/lib directory are >2 years old. I don't know how to check if they were properly compiled/marked as executable, or if one (or more) are triggering the messages.
    • Does the fact that the ixmp still functions as intended/tests pass indicate that the offending code is not used?

@khaeru khaeru mentioned this issue Jan 11, 2020
Closed
khaeru added a commit to iiasa/message_ix that referenced this issue Feb 26, 2020
@khaeru
Copy console noise fix from iiasa/ixmp#247
d54243c 
- jpype-project/jpype#561
- iiasa/ixmp#229
- iiasa/ixmp#247
@khaeru khaeru mentioned this issue Apr 5, 2021
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@zikolach zikolach

@khaeru khaeru

Labels
bug
Projects
None yet
Milestone
2.0
Development

Successfully merging a pull request may close this issue.

Suppress Java noise on Windows/AppVeyor khaeru/ixmp
2 participants
@zikolach @khaeru