X-Git-Url: http://git.kpe.io/?a=blobdiff_plain;f=logger.lisp;h=9a4b8f1b7bb3d82690a7bbe8c9a4d1330694e587;hb=6c1474d89e0dd6f5bf561fb70aaf0ba0929e6176;hp=16a47aff2e5336703a96456c2aba9f48803629ce;hpb=f4a678d829c00ccfe0703b18a150332a4520bd85;p=irc-logger.git diff --git a/logger.lisp b/logger.lisp index 16a47af..9a4b8f1 100644 --- a/logger.lisp +++ b/logger.lisp @@ -4,12 +4,13 @@ ;;;; Purpose: A IRC logging bot ;;;; Author: Kevin Rosenberg -(in-package irc-logger) +(in-package #:irc-logger) (defvar *daemon-monitor-process* nil "Process of background monitor.") +(defparameter *timeout* 60) (defclass channel () - ((name :initarg :name :reader name + ((name :initarg :name :reader c-name :documentation "Name of channel.") (streams :initarg :streams :reader streams :documentation "List of output streams.") @@ -22,7 +23,7 @@ :documentation "IRC connection object.") (handler :initform nil :accessor handler :documentation "Background handler process.") - (nick :initarg :nick :reader nickname + (nick :initarg :nick :reader l-nickname :documentation "Nickname of the bot.") (password :initarg :password :reader password :documentation "Nickname's nickserver password.") @@ -30,9 +31,9 @@ :documentation "Connected IRC server.") (channel-names :initarg :channel-names :accessor channel-names :documentation "List of channel names.") - (realname :initarg :realname :reader realname + (realname :initarg :realname :reader l-realname :documentation "Realname for cl-irc") - (username :initarg :username :reader username + (username :initarg :username :reader l-username :documentation "Username for cl-irc") (logging-stream :initarg :logging-stream :reader logging-stream :documentation "logging-stream for cl-irc.") @@ -66,6 +67,10 @@ :documentation "Time of last, potentially active, warning message."))) +(defmethod print-object ((obj logger) stream) + (print-unreadable-object (obj stream :type t :identity t) + (format stream "~A" (l-nickname obj)))) + (defvar *loggers* nil "List of active loggers.") (defparameter *user-address-scanner* @@ -76,7 +81,7 @@ :case-insensitive-mode t)) (defun find-logger-with-nick (nick) - (find nick (the list *loggers*) :test #'string-equal :key #'nickname)) + (find nick (the list *loggers*) :test #'string-equal :key #'l-nickname)) (defun find-logger-with-connection (conn) (find conn (the list *loggers*) :test #'eq :key #'connection)) @@ -85,17 +90,29 @@ (string-left-trim '(#\#) name)) (defun find-channel-with-name (logger name) - (find name (the list (channels logger)) :test #'string-equal :key #'name)) + (find name (the list (channels logger)) :test #'string-equal :key #'c-name)) (defun make-output-name (name year month day) (format nil "~A-~4,'0D.~2,'0D.~2,'0D" (canonicalize-channel-name name) year month day)) +(defmacro with-decoding ((utime &optional zone) &body body) + `(multiple-value-bind + (second minute hour day-of-month month year day-of-week daylight-p zone) + (decode-universal-time ,utime ,@(if zone (list zone))) + (declare (ignorable second minute hour day-of-month month year day-of-week daylight-p zone)) + ,@body)) + +(defun format-utime (utime &optional zone) + (with-decoding (utime zone) + (format nil "~2,'0D:~2,'0D:~2,'0D" hour minute second))) + +(defun format-date-time (utime &key stream) + (with-decoding (utime) + (format stream "~4,'0D/~2,'0D/~2,'0D ~2,'0D:~2,'0D:~2,'0D" year month day-of-month hour minute second))) + (defun make-output-name-utime (name utime) - (multiple-value-bind - (second minute hour day-of-month month year day-of-week daylight-p zone) - (decode-universal-time utime) - (declare (ignore second minute hour day-of-week daylight-p zone)) + (with-decoding (utime 0) (make-output-name name year month day-of-month))) (defgeneric write-file-header (format channel-name stream)) @@ -129,6 +146,9 @@ (defmethod log-file-path (output-root channel-name year month day (format (eql :sexp))) (%log-file-path output-root channel-name year month day "sexp")) +(defmethod log-file-path (output-root channel-name year month day (format (eql :binary))) + (%log-file-path output-root channel-name year month day "bin")) + (defmethod log-file-path (output-root channel-name year month day (format (eql :text))) (%log-file-path output-root channel-name year month day "txt")) @@ -137,11 +157,8 @@ (defun log-file-path-utime (output-root channel-name format utime) - (multiple-value-bind - (second minute hour day month year day-of-week daylight-p zone) - (decode-universal-time utime) - (declare (ignore second minute hour day-of-week daylight-p zone)) - (log-file-path output-root channel-name year month day format))) + (with-decoding (utime 0) + (log-file-path output-root channel-name year month day-of-month format))) (defun get-stream (channel istream) (elt (streams channel) istream)) @@ -159,15 +176,15 @@ (setf (elt (current-output-names channel) istream) value)) (defun ensure-output-stream-for-unichannel (utime logger channel istream) - (let ((name (make-output-name-utime (name channel) utime))) + (let ((name (make-output-name-utime (c-name channel) utime))) (unless (string= name (get-output-name channel istream)) (when (get-stream channel istream) (write-file-footer (get-format logger istream) - (name channel) + (c-name channel) (get-stream channel istream)) (close (get-stream channel istream))) (setf (get-output-name channel istream) name) - (let ((path (log-file-path-utime (output-root channel) (name channel) + (let ((path (log-file-path-utime (output-root channel) (c-name channel) (get-format logger istream) utime))) (unless (probe-file path) (ensure-directories-exist path) @@ -175,7 +192,7 @@ (open path :direction :output :if-exists :error :if-does-not-exist :create)) (write-file-header (get-format logger istream) - (name channel) + (c-name channel) (get-stream channel istream)) (close (get-stream channel istream))) (setf (get-stream channel istream) @@ -197,27 +214,6 @@ (open (user-output logger) :direction :output :if-exists :append :if-does-not-exist :create))))))) -(defun format-date-time (utime) - (multiple-value-bind - (second minute hour day-of-month month year day-of-week daylight-p zone) - (decode-universal-time utime) - (declare (ignore day-of-week daylight-p zone)) - (format nil "~4,'0D/~2,'0D/~2,'0D ~2,'0D:~2,'0D:~2,'0D" year month day-of-month hour minute second))) - -(defun format-utime (utime) - (multiple-value-bind - (second minute hour day-of-month month year day-of-week daylight-p zone) - (decode-universal-time utime) - (declare (ignore day-of-month month year day-of-week daylight-p zone)) - (format nil "~2,'0D:~2,'0D:~2,'0D" hour minute second))) - -(defun format-utime-short (utime) - (multiple-value-bind - (second minute hour day-of-month month year day-of-week daylight-p zone) - (decode-universal-time utime) - (declare (ignore second day-of-month month year day-of-week daylight-p zone)) - (format nil "~2,'0D:~2,'0D" hour minute))) - (defun user-address (msg) (let ((split (split *user-address-scanner* (raw-message-string msg) :with-registers-p t))) @@ -269,14 +265,15 @@ (defmethod %output-event ((format (eql :sexp)) stream utime type channel source text msg unichannel) (with-standard-io-syntax - (if unichannel - (format stream "(~S ~S ~S ~S ~S)~%" utime type source text (last-sexp-field type msg)) + (let ((cl:*print-case* :downcase)) + (if unichannel + (format stream "(~S ~S ~S ~S ~S)~%" utime type source text (last-sexp-field type msg)) (format stream "(~S ~S ~S ~S ~S ~S)~%" utime type source channel text - (last-sexp-field type msg))))) + (last-sexp-field type msg)))))) (defmethod %output-event ((format (eql :text)) stream utime type channel source text msg unichannel) - (format stream "~A " (format-utime utime)) + (format stream "~A " (format-utime utime 0)) (when (and (null unichannel) channel) (format stream "[~A] " channel)) @@ -315,16 +312,15 @@ (defun output-event-for-a-stream (msg type channel text logger istream) (ensure-output-stream (received-time msg) logger channel istream) (%output-event (get-format logger istream) (get-stream channel istream) - (received-time msg) type (name channel) (source msg) text msg + (received-time msg) type (c-name channel) (source msg) text msg (unichannel logger)) (force-output (get-stream channel istream))) (defun log-daemon-message (logger fmt &rest args) - (let ((text (apply #'format nil fmt args)) - (time (get-universal-time))) - (format (get-private-log-stream logger) - "~A ~A~%" (format-date-time time) text) - (force-output (get-private-log-stream logger)) + (let ((text (apply #'format nil fmt args))) + (add-private-log-entry logger "~A" text) + ;;don't daemon messages to the logs + #+ignore (dolist (channel (channels logger)) (dotimes (istream (length (formats logger))) (ensure-output-stream time logger channel istream) @@ -340,11 +336,7 @@ (dolist (logger *loggers*) (case type ((:error :server :kill) - (format (get-private-log-stream logger) - "~A ~A~%" - (format-date-time (received-time msg)) - (raw-message-string msg)) - (force-output (get-private-log-stream logger))) + (add-private-log-entry logger "~A" (raw-message-string msg))) ((:quit :nick) ;; send to all channels that a nickname is joined (let* ((user (find-user (connection logger) @@ -375,17 +367,31 @@ (unknown-log-stream logger) *standard-output*)) +(defun add-log-entry (stream fmt &rest args) + (handler-case + (progn + (format-date-time (get-universal-time) :stream stream) + (write-char #\space stream) + (apply #'format stream fmt args) + (write-char #\newline stream) + (force-output stream)) + (error (e) + (warn "Error ~A when trying to add-log-entry '~A'." e + (apply #'format nil fmt args))))) + +(defun add-private-log-entry (logger fmt &rest args) + (apply #'add-log-entry + (if (get-private-log-stream logger) + (get-private-log-stream logger) + *standard-output*) + fmt args)) + (defun privmsg-hook (msg) (let ((logger (find-logger-with-connection (connection msg))) (channel (first (arguments msg)))) (cond - ((equal channel (nickname logger)) - (format - (get-private-log-stream logger) - "~A ~A~%" - (format-date-time (get-universal-time)) - (raw-message-string msg)) - (force-output (get-private-log-stream logger))) + ((equal channel (l-nickname logger)) + (add-private-log-entry logger "~A" (raw-message-string msg))) (t (output-event msg :privmsg channel (trailing-argument msg)))))) @@ -411,46 +417,29 @@ (channel (first (arguments msg))) (who-kicked (second (arguments msg)))) (output-event msg :kick channel who-kicked) - (when (string-equal (nickname logger) who-kicked) - (format - (get-private-log-stream logger) - "~A Logging daemon ~A has been kicked from ~A (~A)~%" - (format-date-time (received-time msg)) - (nickname logger) - channel - (trailing-argument msg)) - (force-output (get-private-log-stream logger)) - (daemon-sleep 1) + (when (string-equal (l-nickname logger) who-kicked) + (add-private-log-entry + logger + "Logging daemon ~A has been kicked from ~A (~A)" + (l-nickname logger) channel (trailing-argument msg)) + (daemon-sleep 5) (remove-channel-logger logger channel) - (daemon-sleep 1) + (daemon-sleep 10) (add-channel-logger logger channel) - (format - (get-private-log-stream logger) - "~A Rejoined ~A~%" - (format-date-time (received-time msg)) - channel) - (force-output (get-private-log-stream logger))))) + (add-private-log-entry logger "Rejoined ~A" channel)))) (defun notice-hook (msg) (let ((logger (find-logger-with-connection (connection msg))) (channel (first (arguments msg)))) (cond ((and (string-equal (source msg) "NickServ") - (string-equal channel (nickname logger)) + (string-equal channel (l-nickname logger)) (string-equal "owned by someone else" (trailing-argument msg))) (if logger (privmsg (connection msg) (source msg) (format nil "IDENTIFY ~A" (password logger))) - (format - (get-private-log-stream logger) - "~A NickServ asks for identity with connection not found.~%" - (format-date-time (received-time msg))))) - ((equal channel (nickname logger)) - (format - (get-private-log-stream logger) - "~A ~A~%" - (format-date-time (get-universal-time)) - (raw-message-string msg)) - (force-output (get-private-log-stream logger))) + (add-private-log-entry logger "NickServ asks for identity with connection not found."))) + ((equal channel (l-nickname logger)) + (add-private-log-entry logger "~A" (raw-message-string msg))) (t (output-event msg :notice channel (trailing-argument msg)))))) @@ -491,12 +480,7 @@ (defun invite-hook (msg) (let ((logger (find-logger-with-connection (connection msg)))) - (format - (get-private-log-stream logger) - "~A ~A~%" - (format-date-time (get-universal-time)) - (raw-message-string msg)) - (force-output (get-private-log-stream logger)))) + (add-private-log-entry logger "~A" (raw-message-string msg)))) (defun make-a-channel (name formats output) @@ -561,13 +545,10 @@ ;; nothing to do ) (t - (let ((logger (find-logger-with-connection (connection msg)))) - (format (get-unknown-log-stream - (find-logger-with-connection (connection msg))) - "~A ~A~%" - (format-date-time (received-time msg )) - (raw-message-string msg)) - (force-output (get-unknown-log-stream logger))))) + (add-log-entry + (get-unknown-log-stream (find-logger-with-connection (connection msg))) + "~A" + (raw-message-string msg)))) result)) (defun create-logger (nick server &key channels output password @@ -630,20 +611,23 @@ nick) nil) (t - (ignore-errors (irc:quit (connection logger) "")) - (stop-background-message-handler (handler logger)) + (ignore-errors (quit-with-timeout (connection logger) "")) + (ignore-errors (stop-background-message-handler (handler logger))) (sleep 1) - (dolist (channel (channels logger)) - (let ((c (connection logger))) - (when c - (ignore-errors (remove-channel c (find-channel c (name channel))))))) + (ignore-errors + (let* ((c (connection logger)) + (user (find-user c (l-nickname logger)))) + (when (and c user) + (dolist (channel (channels logger)) + (remove-channel user channel))))) + (ignore-errors (add-private-log-entry logger "Deleting loggers with nick of '~A' [remove-logger]." nick)) (when (private-log-stream logger) (close (private-log-stream logger))) (when (unknown-log-stream logger) (close (unknown-log-stream logger))) (setq *loggers* - (delete nick *loggers* :test #'string-equal :key #'nickname)) + (delete nick *loggers* :test #'string-equal :key #'l-nickname)) t)))) (defun add-logger (nick server &key channels output (password "") @@ -651,18 +635,34 @@ (logging-stream t) (async t) (formats '(:sexp))) (when (find-logger-with-nick nick) - (format - (get-private-log-stream (find-logger-with-nick nick)) - "~A Closing previously active connection [add-logger].~%" - (format-date-time (get-universal-time))) + (add-private-log-entry (find-logger-with-nick nick) + "Closing previously active connection [add-logger].") (ignore-errors (remove-logger nick))) - (let ((logger (create-logger nick server :channels channels :output output - :logging-stream logging-stream :password password - :realname realname :username username - :private-log private-log - :unknown-log unknown-log - :formats formats - :async async))) + (add-private-log-entry nil "Calling create-logger [add-logger].~%") + (let ((logger + (do ((new-logger + (mp:with-timeout (*timeout* nil) + (create-logger nick server :channels channels :output output + :logging-stream logging-stream :password password + :realname realname :username username + :private-log private-log + :unknown-log unknown-log + :formats formats + :async async)) + (mp:with-timeout (*timeout* nil) + (create-logger nick server :channels channels :output output + :logging-stream logging-stream :password password + :realname realname :username username + :private-log private-log + :unknown-log unknown-log + :formats formats + :async async)))) + (new-logger + (progn + (add-private-log-entry nil "Acquired new logger ~A." new-logger) + new-logger)) + (add-private-log-entry nil "Timeout trying to create new logger [add-logger].")))) + (add-private-log-entry logger "Pushing newly created logger ~A [add-logger].~%" logger) (push logger *loggers*) (start-logger logger async) logger)) @@ -670,11 +670,7 @@ (defun add-channel-logger (logger channel-name) (cond ((find-channel-with-name logger channel-name) - (format (get-private-log-stream logger) - "~A Channel ~A already in logger ~A.~%" - (format-date-time (get-universal-time)) - channel-name logger) - (force-output (get-private-log-stream logger)) + (add-private-log-entry logger "Channel ~A already in logger ~A." channel-name logger) nil) (t (let ((channel (make-a-channel channel-name (formats logger) (user-output logger)))) @@ -693,16 +689,13 @@ (setf (get-stream channel i) nil))) (setf (channels logger) (delete channel-name (channels logger) :test #'string-equal - :key #'name)) + :key #'c-name)) (setf (channel-names logger) (delete channel-name (channel-names logger) :test #'string-equal)) t) (t - (format - (get-private-log-stream logger) - "~A Channel name ~A not found in logger ~A.~%" - (format-date-time (get-universal-time)) - channel-name logger) + (add-private-log-entry + logger "Channel name ~A not found in logger ~A." channel-name logger) nil)))) (defun add-hook-logger (logger class hook) @@ -717,19 +710,15 @@ (let ((target (second (arguments msg))) (logger (find-logger-with-connection (connection msg)))) (when (and (stringp target) - (string-equal target (nickname logger))) + (string-equal target (l-nickname logger))) (setf (warning-message-utime logger) (received-time msg))) - (format (get-private-log-stream logger) - "~A Killed by ~A~%" - (format-date-time (received-time msg)) - (source msg)) - (force-output (get-private-log-stream logger)))) + (add-private-log-entry logger "Killed by ~A" (source msg)))) (defun error-hook (msg) (let ((text (trailing-argument msg)) (logger (find-logger-with-connection (connection msg)))) (when (and (stringp text) - (zerop (search (format nil "Closing Link: ~A" (nickname logger)) text))) + (zerop (search (format nil "Closing Link: ~A" (l-nickname logger)) text))) (setf (warning-message-utime logger) (received-time msg))) (output-event msg :error nil (trailing-argument msg)))) @@ -750,21 +739,33 @@ ;; avoid generating too many reconnect messages in the logs (when (or (null (warning-message-utime logger)) (< (- (get-universal-time) (warning-message-utime logger)) 300)) - (log-daemon-message logger "Disconnected. Attempting reconnection at ~A." - (format-date-time (get-universal-time))))) + (log-daemon-message logger "Disconnected. Attempting reconnection."))) (defun log-reconnection (logger) - (log-daemon-message - logger - "Connection restablished at ~A." (format-date-time (get-universal-time)))) + (log-daemon-message logger "Connection restablished.")) +#+ignore (defun is-connected (logger) + (%is-connected logger)) + + +(defun is-connected (logger) + #-allegro (%is-connected logger) + #+allegro (mp:with-timeout (*timeout* nil) + (%is-connected logger))) + +(defun quit-with-timeout (connection msg) + #-allegro (quit connection msg) + #+allegro (mp:with-timeout (*timeout* nil) + (quit connection msg))) + +(defun %is-connected (logger) (when (ignore-errors (ping (connection logger) (server logger))) (dotimes (i 20) (when (and (last-pong logger) (< (- (get-universal-time) (last-pong logger)) 21)) - (return-from is-connected t)) - (sleep 1)))) + (return-from %is-connected t)) + (daemon-sleep 1)))) (let (*recon-nick* *recon-server* *recon-username* *recon-realname* @@ -781,11 +782,11 @@ (log-disconnection logger) (when (connection logger) - (ignore-errors (quit (connection logger) "Client terminated by server")) - (setf *recon-nick* (nickname logger) + (ignore-errors (quit-with-timeout (connection logger) "Client terminated by server")) + (setf *recon-nick* (l-nickname logger) *recon-server* (server logger) - *recon-username* (username logger) - *recon-realname* (realname logger) + *recon-username* (l-username logger) + *recon-realname* (l-realname logger) *recon-password* (password logger) *recon-async* (async logger) *recon-user-output* (user-output logger) @@ -813,34 +814,35 @@ (sleep 5) (when (is-connected new-logger) (log-reconnection new-logger))))) - - ) + ) ;; end closure (defun daemon-monitor () "This function runs in the background and monitors the connection of the logger." ;; run forever - (do () - () - (block main-loop - (dolist (logger *loggers*) - (do ((warning-time (warning-message-utime logger) (warning-message-utime logger))) - ((or (is-connected logger) (null warning-time))) - (cond - ((and warning-time (> (- (get-universal-time) warning-time) 180)) - ;;give up frequent checking because no disconnection despite waiting - (setf (warning-message-utime logger) nil)) - ((not (is-connected logger)) - (unless warning-time - (setf (warning-message-utime logger) (get-universal-time))) - (attempt-reconnection logger) - ;;after a succesful reconnection, the value of logger will be invalid - (sleep 30) - (return-from main-loop)) - (t - (daemon-sleep 30))))) - (do ((i 0 (1+ i))) - ((or (>= i 20) (some (lambda (logger) (warning-message-utime logger)) *loggers*))) - (daemon-sleep 15))))) - + (loop + do + (monitor-once))) + +(defun monitor-once () + (dolist (logger *loggers*) + (do ((warning-time (warning-message-utime logger) (warning-message-utime logger))) + ((and (is-connected logger) (null warning-time))) + (cond + ((and warning-time (> (- (get-universal-time) warning-time) 180)) + ;;give up frequent checking because no disconnection despite waiting + (setf (warning-message-utime logger) nil)) + ((not (is-connected logger)) + (unless warning-time + (setf (warning-message-utime logger) (get-universal-time))) + (attempt-reconnection logger) + ;;after a succesful reconnection, the value of logger will be invalid + (sleep 30) + (return-from monitor-once)) + (t + (daemon-sleep 30))))) + (do ((i 0 (1+ i))) + ((or (>= i 10) (some (lambda (logger) (warning-message-utime logger)) *loggers*))) + (daemon-sleep 15))) +