OSDN Git Service

Changed log messages and levels.
[shogi-server/shogi-server.git] / shogi_server / player.rb
1 ## $Id$
2
3 ## Copyright (C) 2004 NABEYA Kenichi (aka nanami@2ch)
4 ## Copyright (C) 2007-2012 Daigo Moriwaki (daigo at debian dot org)
5 ##
6 ## This program is free software; you can redistribute it and/or modify
7 ## it under the terms of the GNU General Public License as published by
8 ## the Free Software Foundation; either version 2 of the License, or
9 ## (at your option) any later version.
10 ##
11 ## This program is distributed in the hope that it will be useful,
12 ## but WITHOUT ANY WARRANTY; without even the implied warranty of
13 ## MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
14 ## GNU General Public License for more details.
15 ##
16 ## You should have received a copy of the GNU General Public License
17 ## along with this program; if not, write to the Free Software
18 ## Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
19
20 require 'shogi_server/command'
21
22 module ShogiServer # for a namespace
23
24 class BasicPlayer
25   def initialize
26     @player_id = nil
27     @name = nil
28     @password = nil
29     @rate = 0
30     @estimated_rate = 0
31     @win  = 0
32     @loss = 0
33     @last_game_win = false
34     @rating_group = nil
35     @modified_at = nil
36     @sente = nil
37     @game_name = ""
38   end
39
40   # Idetifier of the player in the rating system
41   attr_accessor :player_id
42
43   # Name of the player
44   attr_accessor :name
45   
46   # Password of the player, which does not include a trip
47   attr_accessor :password
48
49   # Score in the rating sysem
50   attr_accessor :rate
51
52   # Estimated rate for unrated player (rate == 0)
53   # But this value is not persisted and cleared when player logs off.
54   attr_accessor :estimated_rate
55
56   # Number of games for win and loss in the rating system
57   attr_accessor :win, :loss
58   
59   # Group in the rating system
60   attr_accessor :rating_group
61
62   # Last timestamp when the rate was modified
63   attr_accessor :modified_at
64
65   # Whether win the previous game or not
66   attr_accessor :last_game_win
67
68   # true for Sente; false for Gote
69   attr_accessor :sente
70
71   # game name
72   attr_accessor :game_name
73
74   def is_human?
75     return [%r!_human$!, %r!_human@!].any? do |re|
76       re.match(@name)
77     end
78   end
79
80   def is_computer?
81     return !is_human?
82   end
83
84   def modified_at
85     @modified_at || Time.now
86   end
87
88   def rate=(new_rate)
89     if @rate != new_rate
90       @rate = new_rate
91       @modified_at = Time.now
92     end
93   end
94
95   def rated?
96     @player_id != nil
97   end
98
99   def last_game_win?
100     return @last_game_win
101   end
102
103   def simple_player_id
104     if @trip
105       simple_name = @name.gsub(/@.*?$/, '')
106       "%s+%s" % [simple_name, @trip[0..8]]
107     else
108       @name
109     end
110   end
111
112   ##
113   # Parses str in the LOGIN command, sets up @player_id and @trip
114   #
115   def set_password(str)
116     if str && !str.empty?
117       @password = str.strip
118       @player_id   = "%s+%s" % [@name, Digest::MD5.hexdigest(@password)]
119     else
120       @player_id = @password = nil
121     end
122   end
123
124   def set_sente_from_str(str)
125     case str
126     when "+" then @sente = true
127     when "-" then @sente = false
128     else
129       # str should be "*"
130       @sente = nil
131     end
132   end
133 end
134
135
136 class Player < BasicPlayer
137   WRITE_THREAD_WATCH_INTERVAL = 20 # sec
138   def initialize(str, socket, eol=nil)
139     super()
140     @socket = socket
141     @status = "connected"       # game_waiting -> agree_waiting -> start_waiting -> game -> finished
142
143     @protocol = nil             # CSA or x1
144     @eol = eol || "\m"          # favorite eol code
145     @game = nil
146     @mytime = 0                 # set in start method also
147     @socket_buffer = []
148     @main_thread = Thread::current
149     @write_queue = ShogiServer::TimeoutQueue.new(WRITE_THREAD_WATCH_INTERVAL)
150     @player_logger = nil
151     start_write_thread
152   end
153
154   attr_accessor :socket, :status
155   attr_accessor :protocol, :eol, :game, :mytime
156   attr_accessor :main_thread
157   attr_reader :socket_buffer
158   
159   def setup_logger(dir)
160     log_file = File.join(dir, "%s.log" % [simple_player_id])
161     @player_logger = Logger.new(log_file, 'daily')
162     @player_logger.formatter = ShogiServer::Formatter.new
163     @player_logger.level = $DEBUG ? Logger::DEBUG : Logger::INFO  
164     @player_logger.datetime_format = "%Y-%m-%d %H:%M:%S"
165   end
166
167   def log(level, direction, message)
168     return unless @player_logger
169     str = message.chomp
170     case direction
171       when :in
172         str = "IN: %s" % [str]
173       when :out
174         str = "OUT: %s" % [str]
175       else
176         str = "UNKNOWN DIRECTION: %s %s" % [direction, str]
177     end
178     case level
179       when :debug
180         @player_logger.debug(str)
181       when :info
182         @player_logger.info(str)
183       when :warn
184         @player_logger.warn(str)
185       when :error
186         @player_logger.error(str)
187       else
188         @player_logger.debug("UNKNOWN LEVEL: %s %s" % [level, str])
189     end
190   rescue Exception => ex
191     log_error("#{ex.class}: #{ex.message}\n\t#{ex.backtrace[0]}")
192   end
193
194   def kill
195     log_message(sprintf("user %s killed", @name))
196     if (@game)
197       @game.kill(self)
198     end
199     finish
200     Thread::kill(@main_thread)  if @main_thread
201     Thread::kill(@write_thread) if @write_thread
202   end
203
204   def finish
205     if (@status != "finished")
206       @status = "finished"
207       log_message(sprintf("user %s finish", @name))    
208       begin
209         log_debug("Terminating %s's write thread..." % [@name])
210         if @write_thread && @write_thread.alive?
211           write_safe(nil)
212           Thread.pass # help the write_thread to terminate
213         end
214         log_debug("done.")
215       rescue
216         log_message(sprintf("user %s finish failed", @name))    
217       end
218     end
219   end
220
221   def start_write_thread
222     @write_thread = Thread.start do
223       Thread.pass
224       while !@socket.closed?
225         begin
226           str = @write_queue.deq
227           if (str == nil)
228             log_debug("%s's write thread terminated" % [@name])
229             break
230           end
231           if (str == :timeout)
232             log_debug("%s's write queue timed out. Try again..." % [@name])
233             next
234           end
235
236           if r = select(nil, [@socket], nil, 20)
237             r[1].first.write(str)
238             log(:info, :out, str)
239           else
240             log_error("Gave a try to send a message to #{@name}, but it timed out.")
241             break
242           end
243         rescue Exception => ex
244           log_error("Failed to send a message to #{@name}. #{ex.class}: #{ex.message}\t#{ex.backtrace[0]}")
245           break
246         end
247       end # while loop
248       log_error("%s's socket closed." % [@name]) if @socket.closed?
249       log_message("At least %d messages are not sent to the client." % 
250                   [@write_queue.get_messages.size])
251     end # thread
252   end
253
254   #
255   # Wait for the write thread to finish.
256   # This method should be called just before this instance will be freed.
257   #
258   def wait_write_thread_finish(msec=1000)
259     while msec > 0 && @write_thread && @write_thread.alive?
260       sleep 0.1; msec -= 0.1
261     end
262     @player_logger.close if @player_logger
263   end
264
265   #
266   # Note that sending a message is included in the giant lock.
267   #
268   def write_safe(str)
269     @write_queue.enq(str)
270   end
271
272   def to_s
273     if ["game_waiting", "start_waiting", "agree_waiting", "game"].include?(status)
274       if (@sente)
275         return sprintf("%s %s %s %s +", rated? ? @player_id : @name, @protocol, @status, @game_name)
276       elsif (@sente == false)
277         return sprintf("%s %s %s %s -", rated? ? @player_id : @name, @protocol, @status, @game_name)
278       elsif (@sente == nil)
279         return sprintf("%s %s %s %s *", rated? ? @player_id : @name, @protocol, @status, @game_name)
280       end
281     else
282       return sprintf("%s %s %s", rated? ? @player_id : @name, @protocol, @status)
283     end
284   end
285
286   def run(csa_1st_str=nil)
287     while ( csa_1st_str || 
288             str = gets_safe(@socket, (@socket_buffer.empty? ? Default_Timeout : 1)) )
289       time = Time.now
290       log(:info, :in, str) if str && str.instance_of?(String) 
291       $mutex.lock
292       begin
293         if !@write_thread.alive?
294           log_error("%s's write thread is dead. Aborting..." % [@name])
295           return
296         end
297         if (@game && @game.turn?(self))
298           @socket_buffer << str
299           str = @socket_buffer.shift
300         end
301         log_debug("%s (%s)" % [str, @socket_buffer.map {|a| String === a ? a.strip : a }.join(",")])
302
303         if (csa_1st_str)
304           str = csa_1st_str
305           csa_1st_str = nil
306         end
307
308         if (@status == "finished")
309           return
310         end
311         str.chomp! if (str.class == String) # may be strip! ?
312
313         delay = Time.now - time
314         if delay > 5
315           log_warning("Detected a long delay: %.2f sec" % [delay])
316         end
317         cmd = ShogiServer::Command.factory(str, self, time)
318         case cmd.call
319         when :return
320           return
321         when :continue
322           # do nothing
323         else
324           # TODO never reach
325           log_error("Detected a wrong return value for %s" % [cmd])
326         end
327
328       ensure
329         $mutex.unlock
330       end
331     end # enf of while
332     log_warning("%s's socket was suddenly closed" % [@name])
333   end # def run
334 end # class
335
336 end # ShogiServer