OSDN Git Service

Changed log messages and levels.
[shogi-server/shogi-server.git] / shogi_server / player.rb
index 07303cb..471119b 100644 (file)
@@ -1,7 +1,7 @@
 ## $Id$
 
 ## Copyright (C) 2004 NABEYA Kenichi (aka nanami@2ch)
-## Copyright (C) 2007-2008 Daigo Moriwaki (daigo at debian dot org)
+## Copyright (C) 2007-2012 Daigo Moriwaki (daigo at debian dot org)
 ##
 ## This program is free software; you can redistribute it and/or modify
 ## it under the terms of the GNU General Public License as published by
@@ -17,7 +17,7 @@
 ## along with this program; if not, write to the Free Software
 ## Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
 
-require 'monitor'
+require 'shogi_server/command'
 
 module ShogiServer # for a namespace
 
@@ -27,9 +27,14 @@ class BasicPlayer
     @name = nil
     @password = nil
     @rate = 0
+    @estimated_rate = 0
     @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
@@ -44,6 +49,10 @@ class BasicPlayer
   # Score in the rating sysem
   attr_accessor :rate
 
+  # Estimated rate for unrated player (rate == 0)
+  # But this value is not persisted and cleared when player logs off.
+  attr_accessor :estimated_rate
+
   # Number of games for win and loss in the rating system
   attr_accessor :win, :loss
   
@@ -56,6 +65,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
@@ -95,10 +120,21 @@ class BasicPlayer
       @player_id = @password = nil
     end
   end
+
+  def set_sente_from_str(str)
+    case str
+    when "+" then @sente = true
+    when "-" then @sente = false
+    else
+      # str should be "*"
+      @sente = nil
+    end
+  end
 end
 
 
 class Player < BasicPlayer
+  WRITE_THREAD_WATCH_INTERVAL = 20 # sec
   def initialize(str, socket, eol=nil)
     super()
     @socket = socket
@@ -107,20 +143,16 @@ 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
-    @write_queue = []
-    @wq_mon  = Monitor.new
-    @wq_cond = @wq_mon.new_cond
+    @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
   
@@ -174,10 +206,12 @@ class Player < BasicPlayer
       @status = "finished"
       log_message(sprintf("user %s finish", @name))    
       begin
-#        @socket.close if (! @socket.closed?)
-        write_safe(nil)
-        @write_thread.join
-        @player_logger.close if @player_logger
+        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
+        log_debug("done.")
       rescue
         log_message(sprintf("user %s finish failed", @name))    
       end
@@ -188,51 +222,51 @@ class Player < BasicPlayer
     @write_thread = Thread.start do
       Thread.pass
       while !@socket.closed?
-        str = ""
         begin
-          timeout_flg = false
-          @wq_mon.synchronize do
-            if @write_queue.empty?
-              if @wq_cond.wait(15)
-                #timeout
-                timeout_flg = true
-                # log_debug("write_queue health check timeout")
-              end
-            end
-            if !timeout_flg && !@write_queue.empty?
-              str = @write_queue.shift
-              # log_debug("Dequeued %s from %s's write_queue." % [str, @name])
-            end
-          end # synchronize
-          next if timeout_flg
-          break if str == nil # exit
+          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("Sending a message to #{@name} timed up.")
+            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
       end # while loop
-      log_message("terminated %s's write thread" % [@name])
+      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
-  rescue
+  end
 
+  #
+  # Wait for the write thread to finish.
+  # This method should be called just before this instance will be freed.
+  #
+  def wait_write_thread_finish(msec=1000)
+    while msec > 0 && @write_thread && @write_thread.alive?
+      sleep 0.1; msec -= 0.1
+    end
+    @player_logger.close if @player_logger
   end
 
   #
   # Note that sending a message is included in the giant lock.
   #
   def write_safe(str)
-    @wq_mon.synchronize do
-      # log_debug("Enqueuing %s..." % [str])
-      @write_queue.push(str)
-      # log_debug("Enqueued %s into %s's write_queue." % [str, @name])
-      @wq_cond.broadcast
-    end
+    @write_queue.enq(str)
   end
 
   def to_s
@@ -252,6 +286,7 @@ 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
@@ -263,7 +298,7 @@ class Player < BasicPlayer
           @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
@@ -274,206 +309,27 @@ 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
+          log_error("Detected a wrong return value for %s" % [cmd])
         end
+
       ensure
         $mutex.unlock
       end
     end # enf of while
+    log_warning("%s's socket was suddenly closed" % [@name])
   end # def run
 end # class