aiarena / aiarena-web

A website for running the aiarena.net ladder.
https://aiarena.net
GNU General Public License v3.0
93 stars 16 forks source link

Bot crashing with cut logs #241

Closed raspersc2 closed 2 years ago

raspersc2 commented 3 years ago

See the following three games:

https://aiarena.net/matches/518917/ https://aiarena.net/matches/516838/ https://aiarena.net/matches/514451/

Eris crashes but downloading the Error log provides no information as to why the bot crashed.

Below is the error log from one of these games

Matplotlib created a temporary config/cache directory at /tmp/matplotlib-waul1xtm because the default path (/root/.config/matplotlib) is not a writable directory; it is highly recommended to set the MPLCONFIGDIR environment variable to a writable directory, in particular to speed up the import of Matplotlib and to better support multiprocessing.
Starting ladder game...
2021-04-11 12:52:58.801 | INFO     | sc2.protocol:_execute:72 - Client status changed to Status.in_game (was None)
2021-04-11 12:52:58.802 | INFO     | sc2.main:_play_game:326 - Player 2 - Bot Eris(Zerg)
5.0.6 Balance mod recognized.
Version: 4.10.0.75689
2021-04-11 12:52:59.853 | INFO     | MapAnalyzer.MapData:__init__:99 - dev Compiling Golden Wall 5.0.6 
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/site-packages/sklearn/linear_model/_least_angle.py:30: DeprecationWarning: `np.float` is a deprecated alias for the builtin `float`. To silence this warning, use `float` by itself. Doing this will not modify any behavior and is safe. If you specifically wanted the numpy scalar type, use `np.float64` here.
Deprecated in NumPy 1.20; for more details and guidance: https://numpy.org/devdocs/release/1.20.0-notes.html#deprecations
  method='lar', copy_X=True, eps=np.finfo(np.float).eps,
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/site-packages/sklearn/decomposition/_lda.py:29: DeprecationWarning: `np.float` is a deprecated alias for the builtin `float`. To silence this warning, use `float` by itself. Doing this will not modify any behavior and is safe. If you specifically wanted the numpy scalar type, use `np.float64` here.
Deprecated in NumPy 1.20; for more details and guidance: https://numpy.org/devdocs/release/1.20.0-notes.html#deprecations
  EPS = np.finfo(np.float).eps
/home/bot_player2/sc2/distances.py:66: DeprecationWarning: `np.float` is a deprecated alias for the builtin `float`. To silence this warning, use `float` by itself. Doing this will not modify any behavior and is safe. If you specifically wanted the numpy scalar type, use `np.float64` here.
Deprecated in NumPy 1.20; for more details and guidance: https://numpy.org/devdocs/release/1.20.0-notes.html#deprecations
  positions_array: np.ndarray = np.fromiter(flat_positions, dtype=np.float, count=2 * self._units_count).reshape(

 Version dev Map Compilation Progress : 0it [00:00, ?it/s]
 Version dev Map Compilation Progress : 0.2it [00:00,  1.76s/it]
 Version dev Map Compilation Progress : 0.4it [00:00,  1.32s/it]
 Version dev Map Compilation Progress : 0.6000000000000001it [00:00,  1.31s/it]
 Version dev Map Compilation Progress : 0.8it [00:01,  1.24s/it]               
 Version dev Map Compilation Progress : 1.0it [00:01,  1.17s/it]
 Version dev Map Compilation Progress : 1.2it [00:01,  1.12s/it]
 Version dev Map Compilation Progress : 1.4it [00:01,  1.10s/it]
 Version dev Map Compilation Progress : 1.5999999999999999it [00:01,  1.07s/it]
 Version dev Map Compilation Progress : 1.7999999999999998it [00:02,  1.05s/it]
 Version dev Map Compilation Progress : 1.9999999999999998it [00:02,  1.03s/it]
 Version dev Map Compilation Progress : 1.9999999999999998it [00:02,  1.13s/it]

Additional information:

raspersc2 commented 3 years ago

There was a new crash today https://aiarena.net/matches/524911/ The log did have a few extra lines if it's any help

Matplotlib created a temporary config/cache directory at /tmp/matplotlib-rt7x91_f because the default path (/root/.config/matplotlib) is not a writable directory; it is highly recommended to set the MPLCONFIGDIR environment variable to a writable directory, in particular to speed up the import of Matplotlib and to better support multiprocessing.
Starting ladder game...
2021-04-17 07:39:00.968 | INFO     | sc2.protocol:_execute:72 - Client status changed to Status.in_game (was None)
2021-04-17 07:39:00.969 | INFO     | sc2.main:_play_game:326 - Player 1 - Bot Eris(Zerg)
5.0.6 Balance mod recognized.
Version: 4.10.0.75689
2021-04-17 07:39:01.995 | INFO     | MapAnalyzer.MapData:__init__:99 - dev Compiling Ever Dream 5.0.6 
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/site-packages/sklearn/linear_model/_least_angle.py:30: DeprecationWarning: `np.float` is a deprecated alias for the builtin `float`. To silence this warning, use `float` by itself. Doing this will not modify any behavior and is safe. If you specifically wanted the numpy scalar type, use `np.float64` here.
Deprecated in NumPy 1.20; for more details and guidance: https://numpy.org/devdocs/release/1.20.0-notes.html#deprecations
  method='lar', copy_X=True, eps=np.finfo(np.float).eps,
/usr/local/lib/python3.7/importlib/_bootstrap.py:219: RuntimeWarning: numpy.ufunc size changed, may indicate binary incompatibility. Expected 192 from C header, got 216 from PyObject
  return f(*args, **kwds)
/usr/local/lib/python3.7/site-packages/sklearn/decomposition/_lda.py:29: DeprecationWarning: `np.float` is a deprecated alias for the builtin `float`. To silence this warning, use `float` by itself. Doing this will not modify any behavior and is safe. If you specifically wanted the numpy scalar type, use `np.float64` here.
Deprecated in NumPy 1.20; for more details and guidance: https://numpy.org/devdocs/release/1.20.0-notes.html#deprecations
  EPS = np.finfo(np.float).eps
/home/bot_player1/sc2/distances.py:66: DeprecationWarning: `np.float` is a deprecated alias for the builtin `float`. To silence this warning, use `float` by itself. Doing this will not modify any behavior and is safe. If you specifically wanted the numpy scalar type, use `np.float64` here.
Deprecated in NumPy 1.20; for more details and guidance: https://numpy.org/devdocs/release/1.20.0-notes.html#deprecations
  positions_array: np.ndarray = np.fromiter(flat_positions, dtype=np.float, count=2 * self._units_count).reshape(

 Version dev Map Compilation Progress : 0it [00:00, ?it/s]
 Version dev Map Compilation Progress : 0.2it [00:00,  1.02s/it]
 Version dev Map Compilation Progress : 0.4it [00:00,  1.03s/it]
 Version dev Map Compilation Progress : 0.6000000000000001it [00:00,  1.16s/it]
 Version dev Map Compilation Progress : 0.8it [00:00,  1.11s/it]               
 Version dev Map Compilation Progress : 1.0it [00:01,  1.08s/it]
 Version dev Map Compilation Progress : 1.2it [00:01,  1.07s/it]
 Version dev Map Compilation Progress : 1.4it [00:01,  1.05s/it]
 Version dev Map Compilation Progress : 1.5999999999999999it [00:01,  1.04s/it]
 Version dev Map Compilation Progress : 1.7999999999999998it [00:01,  1.03s/it]
 Version dev Map Compilation Progress : 1.9999999999999998it [00:01,  1.01it/s]
/usr/local/lib/python3.7/site-packages/aiohttp/client.py:309: ResourceWarning: Unclosed client session <aiohttp.client.ClientSession object at 0x7ff7f9c4d510>
  **kwargs)
ResourceWarning: Enable tracemalloc to get the object allocation traceback
Unclosed client session
client_session: <aiohttp.client.ClientSession object at 0x7ff7f9c4d510>
eladyaniv01 commented 3 years ago

I suspect matplotlib is the cause, it is not installed on the AC clients and any call to that library results in a crash, can you please assert that not matplotlib usage is being attempted on the ladder?

eladyaniv01 commented 3 years ago

Also i notice that your map analyzer logs indicate dev version which means it could be not up to date with latest version, or setup in a way that might cause some bugs

raspersc2 commented 3 years ago

Matplotlib is installed on the AC clients, it has been used in Eris since day one, I highly doubt this is the issue. We are not trying to plot by the way. Will have a look at map analyzer though, we thought it was up to date with the latest version.

eladyaniv01 commented 3 years ago

you can see that all of the matplotlib imports are inside a method scope, within the map analyzer, that is because matplotlib imported on the module scope( imports at the top of the file) would cause the AC clients to crash. if the AC clients do not crash now, that is new to me, but probably a side effect of some changes we've made, i still doubt it is supporting matplotlib

raspersc2 commented 3 years ago

We are using matplotlib in our bot, not within map analyzer. And it's used in 99% of games without crashing

eladyaniv01 commented 3 years ago

thanks for the information, this needs looking into. @danielvschoor could you have a look ?

raspersc2 commented 3 years ago

matplotlib is likely installed via scikit-image https://github.com/scikit-image/scikit-image/blob/main/requirements/default.txt

eladyaniv01 commented 3 years ago

having it installed is not an issue, calling it on runtime is an issue, AFAIK, but i would like dan to comment on this

raspersc2 commented 3 years ago

Well you changed the subject now! And also not getting to the root of the problem The point is that there is no log as to why it crashed Not only that, this is a recent (past 2 weeks or so) issue. Matplotlib was imported every single game before that (at least 1000 games) without any problems.

eladyaniv01 commented 3 years ago

This is a bit tricky to debug, right now we are almost completely blind as to what is going on in the game while its being run. and the code that governs it, is in Rust, which only dan works with. the issue of absent of logs is known, and is a very high priority to fix, but until that is fixed, we may be able to understand why Eris crashed in this particular instance, i still want to rule out that a very particular edge-usage of something involving matplotlib did not cause this

raspersc2 commented 3 years ago

I don't have 100% proof that this is the case, but I think these crashes were happening where an assert was evaluating to False.

The bug that was causing this should now be fixed on Eris's side (we should wait a few weeks to see if it comes up again), though obviously there is still the issue of the crash traceback not making it to the log file.

lladdy commented 2 years ago

@raspersc2 do you know if this still happens? Wondering whether it was inadvertently fixed or not.

raspersc2 commented 2 years ago

@lladdy I haven't noticed this since my last comment. If it's any use I could look back through Eris's commits to find the code I suspect caused this? In hindsight, I should have posted that here

lladdy commented 2 years ago

@raspersc2 mostly I'm seeking to be able to close this issue if we don't suspect it's a problem with the ladder. I sounds like you suspect it isn't. I will close this for now, but happy to re-open if in the future we conclude it's a ladder problem.