lichess-bot-devs/lichess-bot

trashy debug and error comments

ethicalhacker7192 opened this issue · 6 comments

When I try to debug my scripts for well bots it does not say where the issue is or what line it is even, this is especially annoying when I am trying to make models that learn via deep reinforcement learning.

Like how am I supposed to find the line of the errors when all I see is this!?:

[06/14/23 13:57:53] INFO     --- Process Used. Count: 1. IDs: {'qK8m6S1A'}                                                                                                                                                                                      lichess-bot.py:230
[06/14/23 13:57:56] INFO     +++ https://lichess.org/qK8m6S1A/white Bullet vs AI level 1 (qK8m6S1A)                                                                                                                                                             lichess-bot.py:549
                INFO     *** https://lichess.org/qK8m6S1A/white [player] GuineaBot3: Hi! I'm GuineaBot3. Good luck ! Type !help for a list of commands I can respond to.                                                                                    conversation.py:84
[06/14/23 13:57:57] INFO     *** https://lichess.org/qK8m6S1A/white [player] GuineaBot3: I am currently training so this game will actually help me improve as I am a self learning bot.                                                                        conversation.py:84
                INFO     *** https://lichess.org/qK8m6S1A/white [spectator] GuineaBot3: Hi! I'm GuineaBot3. Type !help for a list of commands I can respond to.                                                                                             conversation.py:84
                INFO                                                                                                                                                                                                                                        lichess-bot.py:654
                INFO     move: 1                                                                                                                                                                                                                            lichess-bot.py:655
                INFO     Searching for time 10000 for game qK8m6S1A                                                                                                                                                                                      engine_wrapper.py:646
                INFO     Backing off play_game(...) for 0.9s (TypeError: 'int' object is not callable)                                                                                                                                                          _common.py:105
[06/14/23 13:57:59] INFO     +++ https://lichess.org/qK8m6S1A/white Bullet vs AI level 1 (qK8m6S1A)                                                                                                                                                             lichess-bot.py:549
                INFO     *** https://lichess.org/qK8m6S1A/white [player] GuineaBot3: Hi! I'm GuineaBot3. Good luck ! Type !help for a list of commands I can respond to.                                                                                    conversation.py:84
                INFO     *** https://lichess.org/qK8m6S1A/white [player] GuineaBot3: I am currently training so this game will actually help me improve as I am a self learning bot.                                                                        conversation.py:84
[06/14/23 13:58:00] INFO     *** https://lichess.org/qK8m6S1A/white [spectator] GuineaBot3: Hi! I'm GuineaBot3. Type !help for a list of commands I can respond to.                                                                                             conversation.py:84
                INFO                                                                                                                                                                                                                                        lichess-bot.py:654
                INFO     move: 1                                                                                                                                                                                                                            lichess-bot.py:655
                INFO     Searching for time 10000 for game qK8m6S1A                                                                                                                                                                                      engine_wrapper.py:646
                INFO     Backing off play_game(...) for 0.1s (TypeError: 'int' object is not callable)                                                                                                                                                          _common.py:105
[06/14/23 13:58:01] INFO     +++ https://lichess.org/qK8m6S1A/white Bullet vs AI level 1 (qK8m6S1A)                                                                                                                                                             lichess-bot.py:549
                INFO     *** https://lichess.org/qK8m6S1A/white [player] GuineaBot3: Hi! I'm GuineaBot3. Good luck ! Type !help for a list of commands I can respond to.                                                                                    conversation.py:84
                INFO     *** https://lichess.org/qK8m6S1A/white [player] GuineaBot3: I am currently training so this game will actually help me improve as I am a self learning bot.                                                                        conversation.py:84
[06/14/23 13:58:02] INFO     *** https://lichess.org/qK8m6S1A/white [spectator] GuineaBot3: Hi! I'm GuineaBot3. Type !help for a list of commands I can respond to.                                                                                             conversation.py:84
                INFO                                                                                                                                                                                                                                        lichess-bot.py:654
                INFO     move: 1                                                                                                                                                                                                                            lichess-bot.py:655
                INFO     Searching for time 10000 for game qK8m6S1A                                                                                                                                                                                      engine_wrapper.py:646
                INFO     Backing off play_game(...) for 0.3s (TypeError: 'int' object is not callable)                                                                                                                                                          _common.py:105
[06/14/23 13:58:04] INFO     +++ https://lichess.org/qK8m6S1A/white Bullet vs AI level 1 (qK8m6S1A)                                                                                                                                                             lichess-bot.py:549
                INFO     *** https://lichess.org/qK8m6S1A/white [player] GuineaBot3: Hi! I'm GuineaBot3. Good luck ! Type !help for a list of commands I can respond to.                                                                                    conversation.py:84
                INFO     *** https://lichess.org/qK8m6S1A/white [player] GuineaBot3: I am currently training so this game will actually help me improve as I am a self learning bot.                                                                        conversation.py:84
                INFO     *** https://lichess.org/qK8m6S1A/white [spectator] GuineaBot3: Hi! I'm GuineaBot3. Type !help for a list of commands I can respond to.                                                                                             conversation.py:84
                INFO                                                                                                                                                                                                                                        lichess-bot.py:654
                INFO     move: 1                                                                                                                                                                                                                            lichess-bot.py:655
                INFO     Searching for time 10000 for game qK8m6S1A                                                                                                                                                                                      engine_wrapper.py:646
                INFO     Backing off play_game(...) for 2.2s (TypeError: 'int' object is not callable)                                                                                                                                                          _common.py:105
[06/14/23 13:58:08] INFO     +++ https://lichess.org/qK8m6S1A/white Bullet vs AI level 1 (qK8m6S1A)             

also please note this is not a example in any way because this is a actual error message. Vebrose did not help me either because it also did not show any lines or what was happening in detail with my local program all it showed was HTTP requests and that kind of thing.

this makes debugging like trying to find the needle in the hay stack.

Can you try #738? You should get better error messages.

Did not work, still trying to find my mystery error:
INFO Backing off play_game(...) for 1.3s (AttributeError: 'str' object has no attribute 'info')

nvm, I just modified my _common.py file from line 95 all to new line 106 this code:

def _log_backoff(details, logger, log_level):
    msg = "Backing off %s(...) for %.1fs (%s)"
    log_args = [details['target'].__name__, details['wait']]
    logger.debug(f"Exception: {traceback.format_exc()}")

    exc_typ, exc, _ = sys.exc_info()
    if exc is not None:
        exc_fmt = traceback.format_exception_only(exc_typ, exc)[-1]
        log_args.append(exc_fmt.rstrip("\n"))
    else:
        log_args.append(details['value'])
    logger.log(log_level, msg, *log_args)
    logger.log(traceback.print_exc())

it now prints the following:

Traceback (most recent call last):
  File "/home/user/.local/lib/python3.10/site-packages/backoff/_sync.py", line 105, in retry
    ret = target(*args, **kwargs)
  File "/home/user/ChessAI2/lichess-bot.py", line 589, in play_game
    engine.play_move(board,
  File "/home/user/ChessAI2/engine_wrapper.py", line 190, in play_move
    self.add_comment(best_move, board)
  File "/home/user/ChessAI2/engine_wrapper.py", line 302, in add_comment
    move_info: MOVE_INFO_TYPE = dict(move.info.copy()) if move.info else {}

You should put this feature in, it is actually really useful for debugging giant 8 file big models.

MarkZH commented

Closed by #738