Author: psmith Date: Sun Jan 21 22:43:03 2007 New Revision: 48

Added: branches/home/psmith/restructure/src/utils/ Modified: branches/home/psmith/restructure/run-yarpc-client.lisp branches/home/psmith/restructure/src/compat/nio-compat-package.lisp branches/home/psmith/restructure/src/compat/utils.lisp branches/home/psmith/restructure/src/io/async-fd.lisp branches/home/psmith/restructure/src/io/nio-server.lisp branches/home/psmith/restructure/src/protocol/yarpc/yarpc-state-machine.lisp branches/home/psmith/restructure/src/statemachine/state-machine.lisp Log: Tidied up logging

Modified: branches/home/psmith/restructure/run-yarpc-client.lisp ============================================================================== --- branches/home/psmith/restructure/run-yarpc-client.lisp (original) +++ branches/home/psmith/restructure/run-yarpc-client.lisp Sun Jan 21 22:43:03 2007 @@ -6,7 +6,7 @@ (sb-thread:make-thread #'(lambda()(nio:start-server 'identity 'identity nil :host "127.0.0.1" :port 9897)) :name "nio-server") (sleep 4) (let ((sm (nio:add-connection "127.0.0.1" 16323 'nio-yarpc:yarpc-client-state-machine))) - (format t "~A toplevel adding conn ~A~%" (nio-compat:get-readable-time) sm) + (format-log t "toplevel adding conn ~A~%" sm) (loop - (format t "~A toplevel Submitting job~%" (nio-compat:get-readable-time) ) - (format t "~A Result of remote-execute ~A~%" (nio-compat:get-readable-time) (nio-yarpc:remote-execute sm "(nio-yarpc:test-rpc-list)")))) + (format-log t "Toplevel Submitting job~%" ) + (format-log t "Result of remote-execute ~A~%" (nio-yarpc:remote-execute sm "(nio-yarpc:test-rpc-list)"))))

Modified: branches/home/psmith/restructure/src/compat/nio-compat-package.lisp ============================================================================== --- branches/home/psmith/restructure/src/compat/nio-compat-package.lisp (original) +++ branches/home/psmith/restructure/src/compat/nio-compat-package.lisp Sun Jan 21 22:43:03 2007 @@ -35,5 +35,5 @@ concurrent-queue add take ;;utils - get-readable-time + format-log ))

Modified: branches/home/psmith/restructure/src/compat/utils.lisp ============================================================================== --- branches/home/psmith/restructure/src/compat/utils.lisp (original) +++ branches/home/psmith/restructure/src/compat/utils.lisp Sun Jan 21 22:43:03 2007 @@ -52,9 +52,13 @@ (let ((current-internal (get-internal-real-time))) (+ universal-base (/ (- current-internal internal-base) internal-time-units-per-second) )))

- (defun get-readable-high-res() + (defun get-readable-high-res-time() (let ((estimated-universal-float (get-universal-high-res))) (multiple-value-bind (estimated-universal estimated-universal-rem) (floor estimated-universal-float) (format nil "~A.~3,'0d"(get-readable-time estimated-universal) (* 1000 estimated-universal-rem)))))

- ) \ No newline at end of file + ) + +;Format the message to destination but prepend a high res time to the message, useful for logging +(defmacro format-log (destination control-string &rest format-arguments) + `(format ,destination (concatenate 'string "~A - " ,control-string) (get-readable-high-res-time) ,@format-arguments))

Modified: branches/home/psmith/restructure/src/io/async-fd.lisp ============================================================================== --- branches/home/psmith/restructure/src/io/async-fd.lisp (original) +++ branches/home/psmith/restructure/src/io/async-fd.lisp Sun Jan 21 22:43:03 2007 @@ -149,7 +149,7 @@

(defun write-more (async-fd) "Write data from ASYNC-FD's write bytebuffer" -#+nio-debug (format t "async-fd:write-more - called with ~A~%" async-fd) + (format-log t "async-fd:write-more - called with ~A~%" async-fd) (with-slots (write-fd foreign-write-buffer close-pending) async-fd #+nio-debug (format t "async-fd:write-more - foreign-write-buffer b4 flip ~A~%" foreign-write-buffer) (nio-buffer:flip foreign-write-buffer)

Modified: branches/home/psmith/restructure/src/io/nio-server.lisp ============================================================================== --- branches/home/psmith/restructure/src/io/nio-server.lisp (original) +++ branches/home/psmith/restructure/src/io/nio-server.lisp Sun Jan 21 22:43:03 2007 @@ -122,7 +122,7 @@ ;; socket i/o available (t (let ((async-fd (gethash fd client-hash))) -#+nio-debug (format t "IO event ~A on ~A~%" event async-fd) + (format-log t "IO event ~A on ~A~%" event async-fd) (unless (null async-fd) (catch 'error-exit (handler-bind ((read-error #'(lambda (x)

Modified: branches/home/psmith/restructure/src/protocol/yarpc/yarpc-state-machine.lisp ============================================================================== --- branches/home/psmith/restructure/src/protocol/yarpc/yarpc-state-machine.lisp (original) +++ branches/home/psmith/restructure/src/protocol/yarpc/yarpc-state-machine.lisp Sun Jan 21 22:43:03 2007 @@ -59,14 +59,14 @@

(defun run-job(&key (wait-on-job-pdw t)) - (format t "~A Server toplevel waiting for job~%" (nio-compat:get-readable-time)) + (format-log t "Server toplevel waiting for job~%") (destructuring-bind (job result-queue) (nio-compat:take nio-yarpc:job-queue :blocking-call wait-on-job-pdw) - (format t "~A Server received job ~A~%" (nio-compat:get-readable-time) job) + (format-log t "Server received job ~A~%" job) (nio-compat:add result-queue (nio-yarpc:execute-call job))))

(defmethod process-outgoing-packet((sm yarpc-state-machine)) - (format t "yarpc-state-machine: process-outgoing-packet called, polling the results-queue ~%") + (format-log t "yarpc-state-machine: process-outgoing-packet called, polling the results-queue ~%" ) (let ((result (nio-compat:take (result-queue sm) :blocking-call nil))) (format t "yarpc-state-machine: process-outgoing-packet got result ~A ~%" result) (when result @@ -75,7 +75,7 @@ ;Process a call method packet by placing it in the job-queue (defmethod process-incoming-packet ((sm yarpc-state-machine) (call call-method-packet)) (assert (eql (state sm) STATE-INITIALISED)) - (format t "yarpc-state-machine:process-incoming-packet called :sm ~A :packet ~A~%" sm call) + (format-log t "yarpc-state-machine:process-incoming-packet called :sm ~A :packet ~A~%" sm call) (nio-compat:add job-queue (list (call-string call) (result-queue sm))) (when +process-jobs-inline+ (run-job :wait-on-job-pdw nil)))

Modified: branches/home/psmith/restructure/src/statemachine/state-machine.lisp ============================================================================== --- branches/home/psmith/restructure/src/statemachine/state-machine.lisp (original) +++ branches/home/psmith/restructure/src/statemachine/state-machine.lisp Sun Jan 21 22:43:03 2007 @@ -57,7 +57,7 @@ (defmethod process-read((sm state-machine)) (with-slots (foreign-read-buffer) sm (let ((incoming-packet (get-packet (get-packet-factory sm) foreign-read-buffer))) - (format t "~A state-machine::process-read - incoming packet: ~A~%" (nio-compat:get-readable-time) incoming-packet) + (format-log t "state-machine::process-read - incoming packet: ~A~%" incoming-packet) (when incoming-packet (when (not (process-incoming-packet sm incoming-packet)) (close-sm sm)))))) @@ -67,7 +67,7 @@ (defmethod process-write((sm state-machine)) (with-slots (foreign-write-buffer) sm (let ((outgoing-packet (process-outgoing-packet sm))) - (format t "~A state-machine::process-write - outgoing packet: ~A~%" (nio-compat:get-readable-time) outgoing-packet) + (format-log t "state-machine::process-write - outgoing packet: ~A~%" outgoing-packet) (when outgoing-packet (write-bytes outgoing-packet foreign-write-buffer)))))