X-Git-Url: http://git.sourceforge.jp/view?p=shogi-server%2Fshogi-server.git;a=blobdiff_plain;f=shogi_server%2Fplayer.rb;h=3a86c960ef17c23d4e39103f3cc4568117bd67d9;hp=c9777e111f4a40cfad5e9a3c259bc8da8f94c194;hb=b5fcb695396012f886d9fd0828dc8ffe36ed36a9;hpb=c81f26d9288d31bedec7e9cbc97ba0e8d90a32d7 diff --git a/shogi_server/player.rb b/shogi_server/player.rb index c9777e1..3a86c96 100644 --- a/shogi_server/player.rb +++ b/shogi_server/player.rb @@ -17,6 +17,8 @@ ## along with this program; if not, write to the Free Software ## Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA +require 'shogi_server/command' + module ShogiServer # for a namespace class BasicPlayer @@ -28,6 +30,10 @@ class BasicPlayer @win = 0 @loss = 0 @last_game_win = false + @rating_group = nil + @modified_at = nil + @sente = nil + @game_name = "" end # Idetifier of the player in the rating system @@ -54,6 +60,22 @@ class BasicPlayer # Whether win the previous game or not attr_accessor :last_game_win + # true for Sente; false for Gote + attr_accessor :sente + + # game name + attr_accessor :game_name + + def is_human? + return [%r!_human$!, %r!_human@!].any? do |re| + re.match(@name) + end + end + + def is_computer? + return !is_human? + end + def modified_at @modified_at || Time.now end @@ -97,6 +119,7 @@ end class Player < BasicPlayer + WRITE_THREAD_WATCH_INTERVAL = 20 # sec def initialize(str, socket, eol=nil) super() @socket = socket @@ -105,26 +128,62 @@ class Player < BasicPlayer @protocol = nil # CSA or x1 @eol = eol || "\m" # favorite eol code @game = nil - @game_name = "" @mytime = 0 # set in start method also - @sente = nil @socket_buffer = [] @main_thread = Thread::current - @mutex_write_guard = Mutex.new + @write_queue = ShogiServer::TimeoutQueue.new(WRITE_THREAD_WATCH_INTERVAL) + @player_logger = nil + start_write_thread end attr_accessor :socket, :status - attr_accessor :protocol, :eol, :game, :mytime, :game_name, :sente + attr_accessor :protocol, :eol, :game, :mytime attr_accessor :main_thread attr_reader :socket_buffer + def setup_logger(dir) + log_file = File.join(dir, "%s.log" % [simple_player_id]) + @player_logger = Logger.new(log_file, 'daily') + @player_logger.formatter = ShogiServer::Formatter.new + @player_logger.level = $DEBUG ? Logger::DEBUG : Logger::INFO + @player_logger.datetime_format = "%Y-%m-%d %H:%M:%S" + end + + def log(level, direction, message) + return unless @player_logger + str = message.chomp + case direction + when :in + str = "IN: %s" % [str] + when :out + str = "OUT: %s" % [str] + else + str = "UNKNOWN DIRECTION: %s %s" % [direction, str] + end + case level + when :debug + @player_logger.debug(str) + when :info + @player_logger.info(str) + when :warn + @player_logger.warn(str) + when :error + @player_logger.error(str) + else + @player_logger.debug("UNKNOWN LEVEL: %s %s" % [level, str]) + end + rescue Exception => ex + log_error("#{ex.class}: #{ex.message}\n\t#{ex.backtrace[0]}") + end + def kill log_message(sprintf("user %s killed", @name)) if (@game) @game.kill(self) end finish - Thread::kill(@main_thread) if @main_thread + Thread::kill(@main_thread) if @main_thread + Thread::kill(@write_thread) if @write_thread end def finish @@ -132,29 +191,57 @@ class Player < BasicPlayer @status = "finished" log_message(sprintf("user %s finish", @name)) begin -# @socket.close if (! @socket.closed?) + log_debug("Terminating %s's write thread..." % [@name]) + if @write_thread && @write_thread.alive? + write_safe(nil) + Thread.pass # help the write_thread to terminate + end + @player_logger.close if @player_logger + log_debug("done.") rescue log_message(sprintf("user %s finish failed", @name)) end end end - def write_safe(str) - @mutex_write_guard.synchronize do - begin - if @socket.closed? - log_warning("%s's socket has been closed." % [@name]) - return - end - if r = select(nil, [@socket], nil, 20) - r[1].first.write(str) - else - log_error("Sending a message to #{@name} timed up.") + def start_write_thread + @write_thread = Thread.start do + Thread.pass + while !@socket.closed? + begin + str = @write_queue.deq + if (str == nil) + log_debug("%s's write thread terminated" % [@name]) + break + end + if (str == :timeout) + log_debug("%s's write queue timed out. Try again..." % [@name]) + next + end + + if r = select(nil, [@socket], nil, 20) + r[1].first.write(str) + log(:info, :out, str) + else + log_error("Gave a try to send a message to #{@name}, but it timed out.") + break + end + rescue Exception => ex + log_error("Failed to send a message to #{@name}. #{ex.class}: #{ex.message}\t#{ex.backtrace[0]}") + break end - rescue Exception => ex - log_error("Failed to send a message to #{@name}. #{ex.class}: #{ex.message}\t#{ex.backtrace[0]}") - end - end + end # while loop + log_error("%s's socket closed." % [@name]) if @socket.closed? + log_message("At least %d messages are not sent to the client." % + [@write_queue.get_messages.size]) + end # thread + end + + # + # Note that sending a message is included in the giant lock. + # + def write_safe(str) + @write_queue.enq(str) end def to_s @@ -174,13 +261,19 @@ class Player < BasicPlayer def run(csa_1st_str=nil) while ( csa_1st_str || str = gets_safe(@socket, (@socket_buffer.empty? ? Default_Timeout : 1)) ) + time = Time.now + log(:info, :in, str) if str && str.instance_of?(String) $mutex.lock begin + if !@write_thread.alive? + log_error("%s's write thread is dead. Aborting..." % [@name]) + return + end if (@game && @game.turn?(self)) @socket_buffer << str str = @socket_buffer.shift end - log_message("%s (%s)" % [str, @socket_buffer.map {|a| String === a ? a.strip : a }.join(",")]) if $DEBUG + log_debug("%s (%s)" % [str, @socket_buffer.map {|a| String === a ? a.strip : a }.join(",")]) if (csa_1st_str) str = csa_1st_str @@ -191,206 +284,26 @@ class Player < BasicPlayer return end str.chomp! if (str.class == String) # may be strip! ? - case str - when "" - # Application-level protocol for Keep-Alive - # If the server gets LF, it sends back LF. - # 30 sec rule (client may not send LF again within 30 sec) is not implemented yet. - write_safe("\n") - when /^[\+\-][^%]/ - if (@status == "game") - array_str = str.split(",") - move = array_str.shift - additional = array_str.shift - if /^'(.*)/ =~ additional - comment = array_str.unshift("'*#{$1.toeuc}") - end - s = @game.handle_one_move(move, self) - @game.fh.print("#{Kconv.toeuc(comment.first)}\n") if (comment && comment.first && !s) - return if (s && @protocol == LoginCSA::PROTOCOL) - end - when /^%[^%]/, :timeout - if (@status == "game") - s = @game.handle_one_move(str, self) - return if (s && @protocol == LoginCSA::PROTOCOL) - end - when :exception - log_error("Failed to receive a message from #{@name}.") - return - when /^REJECT/ - if (@status == "agree_waiting") - @game.reject(@name) - return if (@protocol == LoginCSA::PROTOCOL) - else - write_safe(sprintf("##[ERROR] you are in %s status. AGREE is valid in agree_waiting status\n", @status)) - end - when /^AGREE/ - if (@status == "agree_waiting") - @status = "start_waiting" - if ((@game.sente.status == "start_waiting") && - (@game.gote.status == "start_waiting")) - @game.start - @game.sente.status = "game" - @game.gote.status = "game" - end - else - write_safe(sprintf("##[ERROR] you are in %s status. AGREE is valid in agree_waiting status\n", @status)) - end - when /^%%SHOW\s+(\S+)/ - game_id = $1 - if (LEAGUE.games[game_id]) - write_safe(LEAGUE.games[game_id].show.gsub(/^/, '##[SHOW] ')) - end - write_safe("##[SHOW] +OK\n") - when /^%%MONITORON\s+(\S+)/ - game_id = $1 - if (LEAGUE.games[game_id]) - LEAGUE.games[game_id].monitoron(self) - write_safe(LEAGUE.games[game_id].show.gsub(/^/, "##[MONITOR][#{game_id}] ")) - write_safe("##[MONITOR][#{game_id}] +OK\n") - end - when /^%%MONITOROFF\s+(\S+)/ - game_id = $1 - if (LEAGUE.games[game_id]) - LEAGUE.games[game_id].monitoroff(self) - end - when /^%%HELP/ - write_safe( - %!##[HELP] available commands "%%WHO", "%%CHAT str", "%%GAME game_name +", "%%GAME game_name -"\n!) - when /^%%RATING/ - players = LEAGUE.rated_players - players.sort {|a,b| b.rate <=> a.rate}.each do |p| - write_safe("##[RATING] %s \t %4d @%s\n" % - [p.simple_player_id, p.rate, p.modified_at.strftime("%Y-%m-%d")]) - end - write_safe("##[RATING] +OK\n") - when /^%%VERSION/ - write_safe "##[VERSION] Shogi Server revision #{Revision}\n" - write_safe("##[VERSION] +OK\n") - when /^%%GAME\s*$/ - if ((@status == "connected") || (@status == "game_waiting")) - @status = "connected" - @game_name = "" - else - write_safe(sprintf("##[ERROR] you are in %s status. GAME is valid in connected or game_waiting status\n", @status)) - end - when /^%%(GAME|CHALLENGE)\s+(\S+)\s+([\+\-\*])\s*$/ - command_name = $1 - game_name = $2 - my_sente_str = $3 - if (! Login::good_game_name?(game_name)) - write_safe(sprintf("##[ERROR] bad game name\n")) - next - elsif ((@status == "connected") || (@status == "game_waiting")) - ## continue - else - write_safe(sprintf("##[ERROR] you are in %s status. GAME is valid in connected or game_waiting status\n", @status)) - next - end - - rival = nil - if (League::Floodgate.game_name?(game_name)) - if (my_sente_str != "*") - write_safe(sprintf("##[ERROR] You are not allowed to specify TEBAN %s for the game %s\n", my_sente_str, game_name)) - next - end - @sente = nil - else - if (my_sente_str == "*") - rival = LEAGUE.get_player("game_waiting", game_name, nil, self) # no preference - elsif (my_sente_str == "+") - rival = LEAGUE.get_player("game_waiting", game_name, false, self) # rival must be gote - elsif (my_sente_str == "-") - rival = LEAGUE.get_player("game_waiting", game_name, true, self) # rival must be sente - else - ## never reached - write_safe(sprintf("##[ERROR] bad game option\n")) - next - end - end - if (rival) - @game_name = game_name - if ((my_sente_str == "*") && (rival.sente == nil)) - if (rand(2) == 0) - @sente = true - rival.sente = false - else - @sente = false - rival.sente = true - end - elsif (rival.sente == true) # rival has higher priority - @sente = false - elsif (rival.sente == false) - @sente = true - elsif (my_sente_str == "+") - @sente = true - rival.sente = false - elsif (my_sente_str == "-") - @sente = false - rival.sente = true - else - ## never reached - end - Game::new(@game_name, self, rival) - else # rival not found - if (command_name == "GAME") - @status = "game_waiting" - @game_name = game_name - if (my_sente_str == "+") - @sente = true - elsif (my_sente_str == "-") - @sente = false - else - @sente = nil - end - else # challenge - write_safe(sprintf("##[ERROR] can't find rival for %s\n", game_name)) - @status = "connected" - @game_name = "" - @sente = nil - end - end - when /^%%CHAT\s+(.+)/ - message = $1 - LEAGUE.players.each do |name, player| - if (player.protocol != LoginCSA::PROTOCOL) - player.write_safe(sprintf("##[CHAT][%s] %s\n", @name, message)) - end - end - when /^%%LIST/ - buf = Array::new - LEAGUE.games.each do |id, game| - buf.push(sprintf("##[LIST] %s\n", id)) - end - buf.push("##[LIST] +OK\n") - write_safe(buf.join) - when /^%%WHO/ - buf = Array::new - LEAGUE.players.each do |name, player| - buf.push(sprintf("##[WHO] %s\n", player.to_s)) - end - buf.push("##[WHO] +OK\n") - write_safe(buf.join) - when /^LOGOUT/ - @status = "connected" - write_safe("LOGOUT:completed\n") + delay = Time.now - time + if delay > 5 + log_warning("Detected a long delay: %.2f sec" % [delay]) + end + cmd = ShogiServer::Command.factory(str, self, time) + case cmd.call + when :return return - when /^CHALLENGE/ - # This command is only available for CSA's official testing server. - # So, this means nothing for this program. - write_safe("CHALLENGE ACCEPTED\n") - when /^\s*$/ - ## ignore null string + when :continue + # do nothing else - msg = "##[ERROR] unknown command %s\n" % [str] - write_safe(msg) - log_error(msg) + # TODO never reach end + ensure $mutex.unlock end end # enf of while + log_warning("%s's socket was suddenly closed" % [@name]) end # def run end # class