* No loger use Dependencies.rb in Rails.

[shogi-server/shogi-server.git] / shogi_server / player.rb

diff --git a/shogi_server/player.rb b/shogi_server/player.rb
index c9777e1..c9a63a2 100644 (file)
--- a/shogi_server/player.rb
+++ b/shogi_server/player.rb
@@ -97,6 +97,7 @@ end
 
 
 class Player < BasicPlayer
+  WRITE_THREAD_WATCH_INTERVAL = 20 # sec
   def initialize(str, socket, eol=nil)
     super()
     @socket = socket
@@ -110,7 +111,9 @@ class Player < BasicPlayer
     @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
@@ -118,13 +121,49 @@ class Player < BasicPlayer
   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 +171,50 @@ 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])
+        write_safe(nil)
+        @write_thread.join
+        @player_logger.close if @player_logger
       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("Sending a message to #{@name} timed up.")
+          end
+        rescue Exception => ex
+          log_error("Failed to send a message to #{@name}. #{ex.class}: #{ex.message}\t#{ex.backtrace[0]}")
         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?
+    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 +234,18 @@ class Player < BasicPlayer
   def run(csa_1st_str=nil)
     while ( csa_1st_str || 
             str = gets_safe(@socket, (@socket_buffer.empty? ? Default_Timeout : 1)) )
+      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