50011302bb36

Timing support
[view raw] [browse files]
author Steve Losh <steve@stevelosh.com>
date Tue, 23 May 2017 19:54:56 +0000
parents 60c18fdad2b8
children 2ad170fcb598
branches/tags (none)
files package.lisp src/gdl.lisp src/players/random-ii.lisp src/players/random-zdd.lisp

Changes

--- a/package.lisp	Tue May 23 17:44:34 2017 +0000
+++ b/package.lisp	Tue May 23 19:54:56 2017 +0000
@@ -12,6 +12,8 @@
     :load-rules
     :dump-gdl
     :normalize-rules
+    :sort-moves
+    :time-it
     :bare-term
     :negationp
     :term-predicate
--- a/src/gdl.lisp	Tue May 23 17:44:34 2017 +0000
+++ b/src/gdl.lisp	Tue May 23 19:54:56 2017 +0000
@@ -10,6 +10,27 @@
                   (find-package :ggp-rules))))
 
 
+(defun move< (a b)
+  (string< (structural-string a)
+           (structural-string b)))
+
+(defun sort-moves (moves)
+  (sort (copy-seq moves) #'move<))
+
+
+(defmacro time-it ((run-time-place gc-time-place) &body body)
+  (with-gensyms (start end result gc)
+    `(let* ((sb-ext:*gc-run-time* 0)
+            (,start (get-internal-run-time))
+            (,result (progn ,@body))
+            (,end (get-internal-run-time))
+            (,gc sb-ext:*gc-run-time*))
+       (setf ,gc-time-place (/ ,gc internal-time-units-per-second 1.0)
+             ,run-time-place (/ (- ,end ,start ,gc 0.0)
+                                internal-time-units-per-second))
+       ,result)))
+
+
 ;;;; Files --------------------------------------------------------------------
 (defun read-gdl (filename)
   "Read GDL from the given file"
--- a/src/players/random-ii.lisp	Tue May 23 17:44:34 2017 +0000
+++ b/src/players/random-ii.lisp	Tue May 23 19:54:56 2017 +0000
@@ -1,6 +1,9 @@
 (in-package :scully.players.random-ii)
 
 (defvar *data-file* nil)
+(defvar *current-game* nil)
+(defvar *run* 0.0)
+(defvar *gc* 0.0)
 
 
 ;;;; Random Incomplete-Information Player -------------------------------------
@@ -8,10 +11,11 @@
   ((role :type symbol :accessor rp-role)
    (reasoner :accessor rp-reasoner)
    (information-set :accessor rp-information-set)
-   (turn :initform 0 :accessor rp-turn)))
+   (turn :initform 0 :accessor rp-turn)
+   (game-number :initform 0 :accessor rp-game-number)))
 
 (define-with-macro (random-ii-player :conc-name rp)
-  role reasoner information-set turn)
+  role reasoner information-set turn game-number)
 
 
 (defun percepts-match-p (player state moves percepts)
@@ -46,10 +50,27 @@
                      :test #'equal)))
 
 
+(defun information-set-objects (iset)
+  (apply #'+ (mapcar #'length iset)))
+
+(defun dump-iset (iset)
+  (iterate (for state :in iset)
+           (for i :from 1)
+           (format t "~%State ~D~%" i)
+           (iterate (for term :in state)
+                    (format t "    ~S~%" term))))
+
+
 (defmethod ggp:player-start-game ((player random-ii-player) rules role timeout)
-  (setf *data-file* (open "data-prolog" :direction :output :if-exists :append))
+  (setf *data-file* (open "data-prolog" :direction :output
+                          :if-exists :append
+                          :if-does-not-exist :create)
+        *run* 0.0
+        *gc* 0.0)
+  (sb-ext:gc :full t)
   ;; (format *data-file* "turn,information set size,cons/symbol count~%")
   (let ((reasoner (make-prolog-reasoner)))
+    (incf (rp-game-number player))
     (load-rules reasoner rules)
     (setf (rp-role player) role
           (rp-turn player) 0
@@ -65,17 +86,21 @@
 (defmethod ggp:player-update-game-ii ((player random-ii-player) move percepts)
   (format t "~2%=====================================~%")
   (with-random-ii-player (player)
-    (setf information-set
-          (if move
-            (get-next-information-set player move percepts)
-            (list (initial-state reasoner))))
-    (format *data-file* "~D,~D,~D~%"
+    (incf turn)
+    (setf information-set (scully.gdl:time-it
+                            (*run* *gc*)
+                            (if move
+                              (get-next-information-set player move percepts)
+                              (list (initial-state reasoner)))))
+    (format *data-file* "~A,~D,~D,~D,~D,~,4F,~,4F~%"
+            *current-game*
+            game-number
             turn
             (length information-set)
-            (information-set-objects information-set))))
+            (information-set-objects information-set)
+            *run*
+            *gc*)))
 
-(defun information-set-objects (iset)
-  (apply #'+ (mapcar #'length iset)))
 
 (defmethod ggp:player-select-move ((player random-ii-player) timeout)
   (format t "Selecting move...~%")
@@ -83,7 +108,12 @@
     (format t "Information set size: ~D~%" (length information-set))
     (format t "Information set object count ~D~%"
             (information-set-objects information-set))
-    (random-elt (legal-moves-for reasoner role (first information-set)))))
+    (-<> information-set
+      first
+      (legal-moves-for reasoner role <>)
+      pr
+      scully.gdl:sort-moves
+      first)))
 
 
 ;;;; Run ----------------------------------------------------------------------
@@ -93,5 +123,7 @@
                                 :name "Scully-Random-II"
                                 :port 5002))
 
+(setf *current-game* 'mastermind448)
+
 ;; (ggp:start-player *player* :server :hunchentoot :use-thread t)
 ;; (ggp:kill-player *player*)
--- a/src/players/random-zdd.lisp	Tue May 23 17:44:34 2017 +0000
+++ b/src/players/random-zdd.lisp	Tue May 23 19:54:56 2017 +0000
@@ -2,16 +2,13 @@
 
 (defvar *data-file* nil)
 (defparameter *current-game* 'stratego)
+(defvar *prev-time* 0.0)
+(defvar *prev-gc* 0.0)
+(defvar *run* 0)
+(defvar *gc* 0)
 
 
 ;;;; Random Incomplete-Information Player -------------------------------------
-(defun move< (a b)
-  (string< (structural-string a)
-           (structural-string b)))
-
-(defun sort-moves (moves)
-  (sort (copy-seq moves) #'move<))
-
 (defclass random-zdd-player (ggp:ggp-player)
   ((role :type symbol :accessor rp-role)
    (reasoner :accessor rp-reasoner)
@@ -25,8 +22,12 @@
 
 (defmethod ggp:player-start-game ((player random-zdd-player) rules role timeout)
   (incf (rp-game player))
-  (setf *data-file* (open "data-zdd" :direction :output :if-exists :append))
-  ;; (format *data-file* "turn,information set size,zdd node count,max node count~%")
+  (sb-ext:gc :full t)
+  (setf *data-file* (open "data-zdd" :direction :output
+                          :if-exists :append
+                          :if-does-not-exist :create)
+        *prev-time* 0.0
+        *prev-gc* 0.0)
   (scully.zdd::with-zdd
     (let* ((grounded-rules (-<> rules
                              (with-output-to-string (s)
@@ -67,35 +68,43 @@
   (let ((state-count 0)
         (node-count 0)
         (max-node-count 0)
-        (object-size 0))
+        (object-size 0)
+        (elapsed 0.0)
+        (gc 0.0))
     (scully.zdd::with-zdd
       (with-random-zdd-player (player)
         (format t "Computing next information set...~%")
-        (setf iset
-              (if move
-                (-<> iset
-                  (debug-log <> "  Sprouting...")
-                  (sprout reasoner <> (rp-role player) move)
-                  ;; (progn (format t "After sprouting size: ~D states~%"
-                  ;;                (scully.zdd:zdd-count <>))
-                  ;;        <>)
-                  (debug-log <> "  Happens...")
-                  ;; (let ((*trace-output* *standard-output*))
-                  ;;   (start-profiling :mode :alloc)
-                  ;;   (prog1 (time (apply-happens reasoner <>))
-                  ;;     (stop-profiling)
-                  ;;     (break)))
-                  (let ((*trace-output* *standard-output*))
-                    (time (apply-happens reasoner <>)))
-                  (progn (setf max-node-count (scully.zdd:zdd-node-count <>))
-                         <>)
-                  (debug-log <> "  Filtering percepts...")
-                  (filter-iset-for-percepts reasoner <> role percepts)
-                  (debug-log <> "  Computing next...")
-                  (compute-next-iset reasoner <>)
-                  ;; (progn (dump-iset reasoner <>) <>)
-                  )
-                (initial-iset reasoner)))
+        (setf
+          iset (time-it (*run* *gc*)
+                 (if move
+                   (-<> iset
+                     ;; (debug-log <> "  Sprouting...")
+                     (sprout reasoner <> (rp-role player) move)
+                     ;; (progn (format t "After sprouting size: ~D states~%"
+                     ;;                (scully.zdd:zdd-count <>))
+                     ;;        <>)
+                     ;; (debug-log <> "  Happens...")
+                     ;; (let ((*trace-output* *standard-output*))
+                     ;;   (start-profiling :mode :alloc)
+                     ;;   (prog1 (time (apply-happens reasoner <>))
+                     ;;     (stop-profiling)
+                     ;;     (break)))
+                     ;; (let ((*trace-output* *standard-output*))
+                     ;;   (time (apply-happens reasoner <>)))
+                     (apply-happens reasoner <>)
+                     ;; (progn (setf max-node-count (scully.zdd:zdd-node-count <>))
+                     ;;        <>)
+                     ;; (debug-log <> "  Filtering percepts...")
+                     (filter-iset-for-percepts reasoner <> role percepts)
+                     ;; (debug-log <> "  Computing next...")
+                     (compute-next-iset reasoner <>)
+                     ;; (progn (dump-iset reasoner <>) <>)
+                     )
+                   (initial-iset reasoner)))
+          elapsed (+ *prev-time* *run*)
+          gc (+ *prev-gc* *run*))
+        ;; (dump-iset reasoner iset)
+        ;; (break)
         (debug-log iset "  Counting nodes...")
         (setf state-count (scully.zdd:zdd-count iset)
               node-count (scully.zdd:zdd-node-count iset)
@@ -103,27 +112,32 @@
         (format t "Information set size: ~D states, ~D ZDD nodes~%" state-count node-count)
         (format t "      Iset cons size: ~D conses~%" object-size)
         (format t "       Max iset size: ~D ZDD nodes~%" max-node-count)
-        (format *data-file* "~A,~D,~D,~D,~D,~D,~D~%"
+        (format *data-file* "~A,~D,~D,~D,~D,~D,~D,~,4F,~,4F~%"
                 *current-game*
                 game
                 turn
                 state-count
                 node-count
                 max-node-count
-                object-size)))))
+                object-size
+                elapsed
+                gc)
+        (finish-output *data-file*)))))
 
 (defmethod ggp:player-select-move ((player random-zdd-player) timeout)
   (scully.zdd::with-zdd
     (format t "Selecting move...~%")
     (with-random-zdd-player (player)
       (debug-log iset "  Applying possible...")
-      (setf iset (apply-possible reasoner iset))
+      (setf iset (time-it (*run* *gc*) (apply-possible reasoner iset))
+            *prev-time* *run*
+            *prev-gc* *gc*)
       (debug-log iset "  Calculating moves...")
       ;; (format t "CURRENT ISET:~%")
       ;; (dump-iset reasoner iset)
       ;; (format t "LEGAL MOVES:~%")
       ;; (pr (legal-moves-for reasoner iset role))
-      (pr (first (sort-moves (legal-moves-for reasoner iset role)))))))
+      (pr (first (scully.gdl::sort-moves (legal-moves-for reasoner iset role)))))))
 
 
 ;;;; Run ----------------------------------------------------------------------
@@ -133,8 +147,8 @@
                    :name "Scully-Random-ZDD"
                    :port 5003))
 
-(setf *current-game* 'mastermind448)
-(setf scully.terms::*shuffle-variables* t)
+;; (setf *current-game* 'mastermind448)
+;; (setf scully.terms::*shuffle-variables* t)
 
 ;; (ggp:start-player *player* :server :hunchentoot :use-thread t)
 ;; (ggp:kill-player *player*)