Client Error: Bad Request for url and Aborting by lack of activity

[jdart1]

This just recently started happening. I haven't even updated the engine executable. It's the same engine, but something is different now, in the interface or the server:

2023-03-28 00:28:48,478 chess.engine DEBUG <XBoardProtocol (pid=58029)>: Connection made
2023-03-28 00:28:48,479 chess.engine DEBUG <XBoardProtocol (pid=58029)>: << xboard
2023-03-28 00:28:48,479 chess.engine DEBUG <XBoardProtocol (pid=58029)>: << protover 2
2023-03-28 00:28:48,485 chess.engine DEBUG <XBoardProtocol (pid=58029)>: >> Arasan v23.4.0-40-gec32945 Copyright 1994-2022 by Jon Dart. All Rights Reserved.
2023-03-28 00:28:48,513 chess.engine DEBUG <XBoardProtocol (pid=58029)>: >> feature name=1 setboard=1 san=1 usermove=1 ping=1 ics=1 playother=0 sigint=0 colors=0 analyze=1 debug=1 memory=1 smp=1 variants="nor\
mal" egt="syzygy" option="Favor frequent book moves -spin 50 1 100" option="Favor best book moves -spin 50 1 100" option="Favor high-weighted book moves -spin 100 1 100" option="Randomize book moves -spin 50 \
1 100" option="Can resign -check 1" option="Resign threshold -spin -700 -1000 0" option="Position learning -check 1" option="Strength -spin 100 0 100" option="Use NNUE -check 1" option="NNUE file -string aras\
an-d10-20220723.nnue" option="Move overhead -spin 30 0 1000" myname="Arasan v23.4.0-40-gec32945"
2023-03-28 00:28:48,514 chess.engine DEBUG <XBoardProtocol (pid=58029)>: >> feature done=0
2023-03-28 00:28:48,520 chess.engine DEBUG <XBoardProtocol (pid=58029)>: >> # found 6-man Syzygy tablebases in directory /home/jdart/chess/syzygy:/home/jdart/chess/syzygy-6man/wdl:/home/jdart/chess/syzygy-6ma\
n/dtz
2023-03-28 00:28:48,660 chess.engine DEBUG <XBoardProtocol (pid=58029)>: >> # loaded network from file arasan-d10-20220723.nnue
2023-03-28 00:28:48,661 chess.engine DEBUG <XBoardProtocol (pid=58029)>: >> feature done=1
2023-03-28 00:28:48,661 chess.engine WARNING <XBoardProtocol (pid=58029)>: Rejecting feature san=1
2023-03-28 00:28:48,661 chess.engine DEBUG <XBoardProtocol (pid=58029)>: << rejected san
2023-03-28 00:28:48,661 chess.engine DEBUG <XBoardProtocol (pid=58029)>: << accepted memory
2023-03-28 00:28:48,661 chess.engine DEBUG <XBoardProtocol (pid=58029)>: << accepted smp
2023-03-28 00:28:48,661 chess.engine DEBUG <XBoardProtocol (pid=58029)>: << accepted egt
2023-03-28 00:28:48,661 engine_wrapper DEBUG No paths found for egt type: syzygy.
2023-03-28 00:28:48,662 chess.engine DEBUG <XBoardProtocol (pid=58029)>: << name BOT twitch-bot-blue
2023-03-28 00:28:48,662 chess.engine DEBUG <XBoardProtocol (pid=58029)>: << rating 2764 1544
2023-03-28 00:28:48,662 chess.engine DEBUG <XBoardProtocol (pid=58029)>: << computer
2023-03-28 00:28:48,662 __mp_main__ DEBUG The engine for game qYXvCia6 has pid=58029
2023-03-28 00:28:48,663 __mp_main__ INFO +++ https://lichess.org/qYXvCia6/white Blitz vs BOT twitch-bot-blue (1544?) (qYXvCia6)
2023-03-28 00:29:12,538 __mp_main__ INFO Aborting https://lichess.org/qYXvCia6/white by lack of activity
2023-03-28 00:29:12,540 urllib3.connectionpool DEBUG Starting new HTTPS connection (1): lichess.org:443
2023-03-28 00:29:13,004 urllib3.connectionpool DEBUG https://lichess.org:443 "POST /api/bot/game/qYXvCia6/abort HTTP/1.1" 400 46
2023-03-28 00:29:13,006 backoff DEBUG Giving up api_post(...) after 1 tries (requests.exceptions.HTTPError: 400 Client Error: Bad Request for url: https://lichess.org/api/bot/game/qYXvCia6/abort)
2023-03-28 00:29:13,159 urllib3.connectionpool DEBUG https://lichess.org:443 "GET /api/account/playing HTTP/1.1" 200 None
2023-03-28 00:29:18,552 __mp_main__ INFO Aborting https://lichess.org/qYXvCia6/white by lack of activity
2023-03-28 00:29:18,709 urllib3.connectionpool DEBUG https://lichess.org:443 "POST /api/bot/game/qYXvCia6/abort HTTP/1.1" 400 46
2023-03-28 00:29:18,710 backoff DEBUG Giving up api_post(...) after 1 tries (requests.exceptions.HTTPError: 400 Client Error: Bad Request for url: https://lichess.org/api/bot/game/qYXvCia6/abort)
2023-03-28 00:29:18,864 urllib3.connectionpool DEBUG https://lichess.org:443 "GET /api/account/playing HTTP/1.1" 200 None
2023-03-28 00:29:24,572 __mp_main__ INFO Aborting https://lichess.org/qYXvCia6/white by lack of activity

The last 3 lines just keep repeating. Note that if the interface wants to check if an Xboard engine is still alive, it should use "ping."

[jdart1]

Maybe it's trying to restart a game? If I stop the processes and log in again, I still get: __mp_main__ INFO +++ https://lichess.org/qYXvCia6/white Blitz vs BOT twitch-bot-blue (1544?) (qYXvCia6)

[MarkZH]

How long did those three lines repeat for? I think one way this can happen is that the lichess servers are restarting, in which case the problem would resolve itself once the servers are back online. This should only take a few minutes, though.

[jdart1]

There were numerous repetitions. However, the problem is no longer there this morning. Some better error reporting might be good for this condition.

[MarkZH]

At the moment, I'm stumped as to what happened here. Has the issue happened since the original report? Do you still have the full log from before the error? Seeing all the messages from lichess (especislly the last gameState message) would help in figuring out what happened.

[jdart1]

This has not recurred, so I am closing the issue. Will re-open if it happens again or if I have more info.