winboard/ICC issue
Posted: Fri May 18, 2007 7:27 pm
Lately I've been observing a problem where my program stops accepting matches on ICC. Following is a bit of winboard debug log (Winboard version is 4.2.7a):
6638422 <first : (debug) got cmd (main): ping 6
6638422 <first : (debug) do_command: ping 6
6638422 <first : pong 6
6638422 <first : (debug) in do_pending, list size=0
6638422 <first : (debug) out of do_pending, list size=0
6638422 <first : (debug) got cmd (main): new
6638422 <first : (debug) do_command: new
6638422 <first : (debug) in save_game
6638422 <first : (debug) out of save_game
<ICS: Your ad is #100\015\012(ad sent to 844 players, of whom 205 are eligible)\015\012Your ad is #271\015\012(ad sent to 845 players, of whom 208 are eligible)\015\012aics%
<ICS: Challenge: George40 (2091) ArasanX (2527) rated Standard 15 5\015\012Estimated rating changes: Loss: -30 Draw: -14 Win: +2\015\012You may accept this with "accept George40", decline it with\015\012"decline George40", or propose different parameters.\015\012\007aics%
recognized 'Standard' (-1) as variant normal
>ICS: /tell George40 I'm not quite ready for a new game yet; try again soon.\012/decline George40\012
<ICS: (told George40)\015\012aics%
<ICS: You decline the challenge from George40.\015\012aics%
<ICS: \015\012Challenge: George40 (2091) ArasanX (2527) rated Standard 15 5\015\012Estimated rating changes: Loss: -30 Draw: -14 Win: +2\015\012Creating: George40 (2091) ArasanX (2527) rated Standard 15 5\015\012\007You accept the challenge of George40.\015\012"Seeking" ad #100 removed.\015\012"Seeking" ad #271 removed.\015\012{Game 396 (George40 vs. ArasanX) Creating rated standard match.} *\015\012\015\012<12> rnbqkbnr pppppppp -------- -------- -------- -------- PPPPPPPP RNBQKBNR W -1 1 1 1 1 0 396 George40 ArasanX -1 15 5 39 39 900 900 1 none (0:00) none 1\015\012aics%
recognized 'Standard' (-1) as variant normal
>ICS: /tell George40 I'm not quite ready for a new game yet; try again soon.\012/decline George40\012
Ratings from 'Creating:' George40 2091, ArasanX 2527
Parsing board: rnbqkbnr pppppppp -------- -------- -------- -------- PPPPPPPP RNBQKBNR W -1 1 1 1 1 0 396 George40 ArasanX -1 15 5 39 39 900 900 1 none (0:00) none 1
recognized 'ICS rated standard match' (-1) as variant normal
Remembered ratings: W 2091, B 2527
6647891 >first : level 0 15 5
6647891 >first : name George40
6647891 >first : rating 2527 2091
<ICS: (told George40, who is playing)\015\012aics%
<ICS: Your options are "decline draw", "decline adjourn"\015\012"decline abort", or "decline takeback".\015\012aics%
<ICS: \007\015\012<12> rnbqkbnr pppppppp -------- -------- ---P---- -------- PPP-PPPP RNBQKBNR B 3 1 1 1 1 0 396 George40 ArasanX 1 15 5 39 39 903 900 1 P/d2-d4 (0:02) d4 1\015\012
Parsing board: rnbqkbnr pppppppp -------- -------- ---P---- -------- PPP-PPPP RNBQKBNR B 3 1 1 1 1 0 396 George40 ArasanX 1 15 5 39 39 903 900 1 P/d2-d4 (0:02) d4 1
6649266 >first : time 90000
otim 90300
6649266 >first : usermove 6649266 >first : d4
<ICS: aics%
<ICS: aics%
<ICS: \015\012Your opponent aborted the game at its inception.\015\012{Game 396 (George40 vs. ArasanX) Game aborted by George40 at move 1} *\015\012aics%
GameEnds(34, Game aborted by George40 at move 1, 0)
6666687 >first : result * {Game aborted by George40 at move 1}
6666687 >first : force
6666687 >first : ping 8
>ICS: gameend\012
>ICS: \012
Reset(1, 1) from gameMode 11
recognized 'normal' (-1) as variant normal
GameEnds(0, (null), 2)
6666687 >first : new
random
6666687 >first : ics chessclub.com
6666687 >first : post
6666687 >first : hard
6666687 >first : ping 9
<ICS: Your ad is #471\015\012(ad sent to 823 players, of whom 210 are eligible)\015\012Your ad is #472\015\012(ad sent to 823 players, of whom 209 are eligible)\015\012aics%
<ICS: aics%
<ICS: \015\012Challenge: NowX (2437) ArasanX (2527) rated Standard 15 5\015\012Estimated rating changes: Loss: -20 Draw: -4 Win: +12\015\012NowX is in the computer list.\015\012You may accept this with "accept NowX", decline it with\015\012"decline NowX", or propose different parameters.\015\012\007aics%
recognized 'Standard' (-1) as variant normal
>ICS: /tell NowX I'm not quite ready for a new game yet; try again soon.\012/decline NowX\012
<ICS: (told NowX)\015\012aics%
<ICS: You decline the challenge from NowX.\015\012aics%
<ICS: \015\012Challenge: NowX (2437) ArasanX (2527) rated Standard 15 5\015\012Estimated rating changes: Loss: -20 Draw: -4 Win: +12\015\012NowX is in the computer list.\015\012You may accept this with "accept NowX", decline it with\015\012"decline NowX", or propose different parameters.\015\012\007aics%
recognized 'Standard' (-1) as variant normal
>ICS: /tell NowX I'm not quite ready for a new game yet; try again soon.\012/decline NowX\012
So, two puzzles:
- note that Arasan responded "pong 6" so the "ping count" which is one test Winboard uses for program readiness should succeed. But somehow Winboard thinks it is not ready. I'm still investigating this.
- note that after the first challenge was declined, the second one was accepted - without Arasan issuing an "accept" command. ICC just went ahead and created the game. Then, the ready test fails and Winboard issues a "decline" command (and a message to the opponent) but it is really too late for that because the opponent is already playing. This looks maybe like an ICC problem. Anybody else seen this?
--Jon
6638422 <first : (debug) got cmd (main): ping 6
6638422 <first : (debug) do_command: ping 6
6638422 <first : pong 6
6638422 <first : (debug) in do_pending, list size=0
6638422 <first : (debug) out of do_pending, list size=0
6638422 <first : (debug) got cmd (main): new
6638422 <first : (debug) do_command: new
6638422 <first : (debug) in save_game
6638422 <first : (debug) out of save_game
<ICS: Your ad is #100\015\012(ad sent to 844 players, of whom 205 are eligible)\015\012Your ad is #271\015\012(ad sent to 845 players, of whom 208 are eligible)\015\012aics%
<ICS: Challenge: George40 (2091) ArasanX (2527) rated Standard 15 5\015\012Estimated rating changes: Loss: -30 Draw: -14 Win: +2\015\012You may accept this with "accept George40", decline it with\015\012"decline George40", or propose different parameters.\015\012\007aics%
recognized 'Standard' (-1) as variant normal
>ICS: /tell George40 I'm not quite ready for a new game yet; try again soon.\012/decline George40\012
<ICS: (told George40)\015\012aics%
<ICS: You decline the challenge from George40.\015\012aics%
<ICS: \015\012Challenge: George40 (2091) ArasanX (2527) rated Standard 15 5\015\012Estimated rating changes: Loss: -30 Draw: -14 Win: +2\015\012Creating: George40 (2091) ArasanX (2527) rated Standard 15 5\015\012\007You accept the challenge of George40.\015\012"Seeking" ad #100 removed.\015\012"Seeking" ad #271 removed.\015\012{Game 396 (George40 vs. ArasanX) Creating rated standard match.} *\015\012\015\012<12> rnbqkbnr pppppppp -------- -------- -------- -------- PPPPPPPP RNBQKBNR W -1 1 1 1 1 0 396 George40 ArasanX -1 15 5 39 39 900 900 1 none (0:00) none 1\015\012aics%
recognized 'Standard' (-1) as variant normal
>ICS: /tell George40 I'm not quite ready for a new game yet; try again soon.\012/decline George40\012
Ratings from 'Creating:' George40 2091, ArasanX 2527
Parsing board: rnbqkbnr pppppppp -------- -------- -------- -------- PPPPPPPP RNBQKBNR W -1 1 1 1 1 0 396 George40 ArasanX -1 15 5 39 39 900 900 1 none (0:00) none 1
recognized 'ICS rated standard match' (-1) as variant normal
Remembered ratings: W 2091, B 2527
6647891 >first : level 0 15 5
6647891 >first : name George40
6647891 >first : rating 2527 2091
<ICS: (told George40, who is playing)\015\012aics%
<ICS: Your options are "decline draw", "decline adjourn"\015\012"decline abort", or "decline takeback".\015\012aics%
<ICS: \007\015\012<12> rnbqkbnr pppppppp -------- -------- ---P---- -------- PPP-PPPP RNBQKBNR B 3 1 1 1 1 0 396 George40 ArasanX 1 15 5 39 39 903 900 1 P/d2-d4 (0:02) d4 1\015\012
Parsing board: rnbqkbnr pppppppp -------- -------- ---P---- -------- PPP-PPPP RNBQKBNR B 3 1 1 1 1 0 396 George40 ArasanX 1 15 5 39 39 903 900 1 P/d2-d4 (0:02) d4 1
6649266 >first : time 90000
otim 90300
6649266 >first : usermove 6649266 >first : d4
<ICS: aics%
<ICS: aics%
<ICS: \015\012Your opponent aborted the game at its inception.\015\012{Game 396 (George40 vs. ArasanX) Game aborted by George40 at move 1} *\015\012aics%
GameEnds(34, Game aborted by George40 at move 1, 0)
6666687 >first : result * {Game aborted by George40 at move 1}
6666687 >first : force
6666687 >first : ping 8
>ICS: gameend\012
>ICS: \012
Reset(1, 1) from gameMode 11
recognized 'normal' (-1) as variant normal
GameEnds(0, (null), 2)
6666687 >first : new
random
6666687 >first : ics chessclub.com
6666687 >first : post
6666687 >first : hard
6666687 >first : ping 9
<ICS: Your ad is #471\015\012(ad sent to 823 players, of whom 210 are eligible)\015\012Your ad is #472\015\012(ad sent to 823 players, of whom 209 are eligible)\015\012aics%
<ICS: aics%
<ICS: \015\012Challenge: NowX (2437) ArasanX (2527) rated Standard 15 5\015\012Estimated rating changes: Loss: -20 Draw: -4 Win: +12\015\012NowX is in the computer list.\015\012You may accept this with "accept NowX", decline it with\015\012"decline NowX", or propose different parameters.\015\012\007aics%
recognized 'Standard' (-1) as variant normal
>ICS: /tell NowX I'm not quite ready for a new game yet; try again soon.\012/decline NowX\012
<ICS: (told NowX)\015\012aics%
<ICS: You decline the challenge from NowX.\015\012aics%
<ICS: \015\012Challenge: NowX (2437) ArasanX (2527) rated Standard 15 5\015\012Estimated rating changes: Loss: -20 Draw: -4 Win: +12\015\012NowX is in the computer list.\015\012You may accept this with "accept NowX", decline it with\015\012"decline NowX", or propose different parameters.\015\012\007aics%
recognized 'Standard' (-1) as variant normal
>ICS: /tell NowX I'm not quite ready for a new game yet; try again soon.\012/decline NowX\012
So, two puzzles:
- note that Arasan responded "pong 6" so the "ping count" which is one test Winboard uses for program readiness should succeed. But somehow Winboard thinks it is not ready. I'm still investigating this.
- note that after the first challenge was declined, the second one was accepted - without Arasan issuing an "accept" command. ICC just went ahead and created the game. Then, the ready test fails and Winboard issues a "decline" command (and a message to the opponent) but it is really too late for that because the opponent is already playing. This looks maybe like an ICC problem. Anybody else seen this?
--Jon