r8451: fix background monitor
[irc-logger.git] / logger.lisp
index 1382ef49e434480fb596d29794c809abac14f3d6..15080c17c81de67b6524ecf23f3eb2f1bb11a332 100644 (file)
@@ -1,4 +1,4 @@
-;;;;  -*- Mode: Lisp -*-
+o;;;  -*- Mode: Lisp -*-
 ;;;; $Id: logger.lisp,v 1.11 2003/12/16 21:19:56 krosenberg Exp $
 ;;;;
 ;;;; Purpose: A IRC logging bot 
@@ -6,6 +6,8 @@
 
 (in-package irc-logger)
 
+(defvar *daemon-monitor-process* nil "Process of background monitor.")
+
 (defclass channel ()
   ((name :initarg :name :reader name
         :documentation "Name of channel.")
 
    
 (defclass logger ()
-  ((connection :initarg :connection :reader connection
+  ((connection :initarg :connection :accessor connection
               :documentation "IRC connection object.")
+   (handler :initform nil :accessor handler
+           :documentation "Background handler process.")
    (nick :initarg :nick :reader nickname
         :documentation "Nickname of the bot.")
    (password :initarg :password :reader password
             :documentation "Nickname's nickserver password.")
    (server :initarg :server :reader server
           :documentation "Connected IRC server.")
-   (channels :initarg :channels :reader channels
+   (channel-names :initarg :channel-names :accessor channel-names
+                 :documentation "List of channel names.")
+   (realname :initarg :realname :reader realname
+          :documentation "Realname for cl-irc")
+   (username :initarg :username :reader username
+          :documentation "Username for cl-irc")
+   (logging-stream :initarg :logging-stream :reader logging-stream 
+                  :documentation "logging-stream for cl-irc.")
+   (channels :initarg :channels :accessor channels
             :documentation "List of channels.")
    (user-output :initarg :user-output :reader user-output
                :documentation
               :documentation "T if user-output is directory for individual channel output.")
    (formats :initarg :formats :reader formats
                  :documentation
-                 "A list of output formats.")))
+                 "A list of output formats.")
+   (async :initarg :async :reader async
+                 :documentation
+                 "Whether to use async")
+   (last-pong :initform nil :accessor last-pong
+                 :documentation
+                 "utime of last pong message")
+   (warning-message-utime :initform nil :accessor warning-message-utime
+                 :documentation
+                 "Time of last, potentially active, warning message.")))
 
 (defvar *loggers* nil "List of active loggers.")
 
 (defun find-logger-with-connection (conn)
   (find conn (the list *loggers*) :test #'eq :key #'connection))
 
+(defun canonicalize-channel-name (name)
+  (string-left-trim '(#\#) name))
+
+(defun find-channel-with-name (logger name)
+  (find name (the list (channels logger)) :test #'string-equal :key #'name))
+  
 (defun make-output-name (name year month day)
-    (format nil "~A-~4,'0D.~2,'0D.~2,'0D"
-           (string-left-trim '(#\#) name) year month day))
+    (format nil "~A-~4,'0D.~2,'0D.~2,'0D" (canonicalize-channel-name name)
+           year month day))
 
 (defun make-output-name-utime (name utime)
   (multiple-value-bind
 (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"))
 
+(defmethod log-file-path (output-root channel-name year month day (format string))
+  (%log-file-path output-root channel-name year month day format))
+
 
 (defun log-file-path-utime (output-root channel-name format utime)
   (multiple-value-bind
       (setf (get-stream channel istream)
        (open (user-output logger) :direction :output :if-exists :append)))))))
 
+(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)
     (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)
+(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)
 
 (defmethod %output-event ((format (eql :raw)) stream utime type channel source
                          text msg unichannel)
-  (declare (ignore utime type channel source text text unichannel ))
-  (format stream "~S~%" (string-right-trim '(#\return) 
-                                          (raw-message-string msg))))
+  (declare (ignore utime type channel source text text unichannel))
+  (when msg
+    (format stream "~S~%" 
+           (string-right-trim '(#\return) (raw-message-string msg)))))
+
+(defun last-sexp-field (type msg)
+  (cond
+   ((null msg)
+    nil)
+   ((eq type :kick)
+    (trailing-argument msg))
+   ((need-user-address? type)
+    (user-address msg))))
 
 (defmethod %output-event ((format (eql :sexp)) stream utime type channel source text
                          msg unichannel)
   (if unichannel
-      (format stream "(~S ~S ~S ~S ~S)~%" utime type source text
-             (when (need-user-address? type) (user-address msg)))
-    (format stream "(~S ~S ~S ~S ~S ~S)~%" utime type source channel
-           text (when (need-user-address? type) (user-address msg)))))
+      (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))))
 
 (defmethod %output-event ((format (eql :text)) stream utime type channel source text
                          msg unichannel)
   (when (and (null unichannel) channel)
     (format stream "[~A] " channel))
   
-  (let ((user-address (when (need-user-address? type)  (user-address msg))))
+  (let ((user-address (when (and msg (need-user-address? type)) (user-address msg))))
     (case type
       (:privmsg
        (format stream "<~A> ~A" source text))
        (format stream "-!- ~A changed the topic of ~A to: ~A" source channel text))
       (:notice
        (format stream "-~A:~A- ~A" source channel text))
+      (:daemon
+       (format stream "-!!!- ~A" text))
+      (:server
+       (format stream "-!!!- server send message ~A" source channel text))
+      (:error
+       (format stream "-!!!- error: ~A ~A" source text))
+      (:kill
+       (format stream "-!!!- kill: ~A ~A" source text))
       (t
-     (warn "Unhandled msg type ~A." type))))
+       (warn "Unhandled msg type ~A." type))))
   (write-char #\Newline stream))
 
 (defun output-event-for-a-stream (msg type channel text logger istream)
                  (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)))
+    (dolist (channel (channels logger))
+      (dotimes (istream (length (formats logger)))
+       (ensure-output-stream time logger channel istream)
+       (%output-event  (get-format logger istream) (get-stream channel istream)
+                       time :daemon nil nil text nil
+                       (unichannel logger))
+       (force-output (get-stream channel istream))))))
+
+(defvar *msg*)
 (defun output-event (msg type channel-name &optional text)
+  (setq *msg* msg)
   (dolist (logger *loggers*)
     (case type
-      ((:quit :nick)
+      ((:error :server :kill)
+       ;;send to all channels
        (dolist (channel (channels logger))
         (dotimes (i (length (formats logger)))
           (output-event-for-a-stream msg type channel text logger i))))
+      ((:quit :nick)
+       ;; send to all channels that a nickname is joined
+       (let* ((user (find-user (connection logger)
+                              (case type
+                                (:nick (source msg))
+                                (:quit (source msg)))))
+             (channels (when user (cl-irc::channels user))))
+        (dolist (channel (mapcar
+                          #'(lambda (name) (find-channel-with-name logger name)) 
+                          (mapcar #'cl-irc::name channels)))
+          (when channel
+            (dotimes (i (length (formats logger)))
+              (output-event-for-a-stream msg type channel text logger i))))))
       (t
-       (let* ((channel (find channel-name (the list (channels logger))
-                            :test #'string-equal :key #'name)))
+       ;; msg contains channel name
+       (let* ((channel (find-channel-with-name logger channel-name)))
         (when channel
           (dotimes (i (length (formats logger)))
             (output-event-for-a-stream msg type channel text logger i))))))))
            (warn "NickServ asks for identity with connection not found."))) 
       (output-event msg :notice (first (arguments msg)) (trailing-argument msg))))
 
+(defun ping-hook (msg)
+  (let ((logger (find-logger-with-connection (connection msg))))
+    (pong (connection msg) (server logger))
+    (format *standard-output* "Sending pong to ~A~%" (server logger))))
+
+(defun pong-hook (msg)
+  (let ((logger (find-logger-with-connection (connection msg))))
+    (setf (last-pong logger) (received-time msg))))
+       
 (defun topic-hook (msg)
   (output-event msg :topic (first (arguments msg)) (trailing-argument msg)))
 
 (defun mode-hook (msg)
-  (output-event msg :mode (first (arguments msg))))
-
+  (output-event msg :mode (first (arguments msg)) 
+               (format nil "~{~A~^ ~}" (cdr (arguments msg)))))
+
+(defun make-a-channel (name formats output)
+  (make-instance 'channel
+                :name name
+                :streams (make-array (length formats) :initial-element nil)
+                :output-root (when (and (pathnamep output)
+                                        (null (pathname-name output)))
+                               output)
+                :current-output-names (make-array (length formats)
+                                                  :initial-element nil)))
+  
 (defun make-channels (names formats output)
   (loop for i from 0 to (1- (length names))
-       collect
-       (make-instance 'channel
-                      :name (nth i names)
-                      :streams (make-array (length formats) :initial-element nil)
-                      :output-root (when (and (pathnamep output)
-                                              (null (pathname-name output)))
-                                     output)
-                      :current-output-names (make-array (length formats)
-                                                        :initial-element nil))))
+       collect (make-a-channel (elt names i) formats output)))
 
 (defun is-unichannel-output (user-output)
   "Returns T if output is setup for a single channel directory structure."
   (and (pathnamep user-output) (null (pathname-name user-output))))
-                 
+
+(defun do-connect-and-join (nick server username realname logging-stream channels)
+  (let ((conn (connect :nickname nick :server server
+                      :username username :realname realname
+                      :logging-stream logging-stream)))
+    (mapc #'(lambda (channel) (join conn channel)) channels)
+    (add-hook conn 'irc::irc-privmsg-message 'privmsg-hook)
+    (add-hook conn 'irc::ctcp-action-message 'action-hook)
+    (add-hook conn 'irc::irc-nick-message 'nick-hook)
+    (add-hook conn 'irc::irc-part-message 'part-hook)
+    (add-hook conn 'irc::irc-quit-message 'quit-hook)
+    (add-hook conn 'irc::irc-join-message 'join-hook)
+    (add-hook conn 'irc::irc-kick-message 'kick-hook)
+    (add-hook conn 'irc::irc-mode-message 'mode-hook)
+    (add-hook conn 'irc::irc-topic-message 'topic-hook)
+    (add-hook conn 'irc::irc-notice-message 'notice-hook)
+    (add-hook conn 'irc::irc-rpl_killdone-message 'warning-hook)
+    (add-hook conn 'irc::irc-rpl_closing-message 'warning-hook)
+    (add-hook conn 'irc::irc-error-message 'error-hook)
+    (add-hook conn 'irc::irc-ping-message 'ping-hook)
+    (add-hook conn 'irc::irc-pong-message 'pong-hook)
+    (add-hook conn 'irc::irc-kill-message 'kill-hook)
+    conn))
+
 (defun create-logger (nick server &key channels output password
-                     (logging-stream t) (formats '(:text)))
+                                      realname username async
+                                      (logging-stream t) (formats '(:text)))
   "OUTPUT may be a pathname or a stream"
   ;; check arguments
-  (assert channels)
   (assert formats)
-  (if (atom channels)
+  (if (and channels (atom channels))
       (setq channels (list channels)))
   (if (atom formats)
       (setq formats (list formats)))
   (if (stringp output)
       (setq output (parse-namestring output)))
-  (let* ((conn         (connect :nickname nick :server server
-                        :logging-stream logging-stream))
+  (let* ((conn (do-connect-and-join nick server username realname logging-stream channels))
         (logger (make-instance
                  'logger
                  :connection conn
                  :password password
                  :server server
                  :channels (make-channels channels formats output)
+                 :channel-names channels
+                 :username username
+                 :realname realname
+                 :async async
+                 :logging-stream logging-stream
                  :user-output output
                  :formats formats
                  :unichannel (is-unichannel-output output))))
-    
-    (mapc #'(lambda (channel) (join conn channel)) channels)
-    (add-hook conn 'irc::irc-privmsg-message 'privmsg-hook)
-    (add-hook conn 'irc::ctcp-action-message 'action-hook)
-    (add-hook conn 'irc::irc-nick-message 'nick-hook)
-    (add-hook conn 'irc::irc-part-message 'part-hook)
-    (add-hook conn 'irc::irc-quit-message 'quit-hook)
-    (add-hook conn 'irc::irc-join-message 'join-hook)
-    (add-hook conn 'irc::irc-kick-message 'kick-hook)
-    (add-hook conn 'irc::irc-mode-message 'mode-hook)
-    (add-hook conn 'irc::irc-topic-message 'topic-hook)
-    (add-hook conn 'irc::irc-notice-message 'notice-hook)
+    (unless *daemon-monitor-process*
+      (setq *daemon-monitor-process* (cl-irc::start-process 'daemon-monitor "logger-monitor")))
     logger))
 
 (defun start-logger (logger async)
   (if async
-      (start-background-message-handler (connection logger))
+      (setf (handler logger)
+       (start-background-message-handler (connection logger)))
       (read-message-loop (connection logger))))
 
-(defun quit-logger (nick)
+(defun remove-logger (nick)
   "Quit the active connection with nick and remove from active list."
   (let ((logger (find-logger-with-nick nick)))
     (cond
        (warn "No active connection found with nick ~A." nick)
        nil)
       (t
-       (irc:quit (connection logger))
+       (ignore-errors (irc:quit (connection logger) ""))
+       (stop-background-message-handler (handler logger))
        (sleep 1)
        (dolist (channel (channels logger))
-        (dotimes (i (length (streams channel)))
-        (when (streamp (get-stream channel i))
-          (close (get-stream channel i))
-          (setf (get-stream channel i) nil))))
+        (let ((c (connection logger)))
+          (when c
+            (ignore-errors (remove-channel c (find-channel c (name channel)))))))
        (setq *loggers*
             (delete nick *loggers*  :test #'string-equal :key #'nickname))
        t))))
 
 (defun add-logger (nick server &key channels output (password "")
-                  (logging-stream t) (async t) (formats '(:text)))
+                                   realname username
+                                   (logging-stream t) (async t) (formats '(:text)))
   (when (find-logger-with-nick nick)
     (warn "Closing previously active connection.")
-    (quit-logger nick))
+    (ignore-errors (remove-logger nick)))
   (let ((logger (create-logger nick server :channels channels :output output
                               :logging-stream logging-stream :password password
-                              :formats formats)))
+                              :realname realname :username username
+                              :formats formats
+                              :async async)))
     (push logger *loggers*)
     (start-logger logger async)
     logger))
 
+(defun add-channel-logger (logger channel-name)
+  (cond
+    ((find-channel-with-name logger channel-name)
+     (warn "Channel ~A already in logger ~A." channel-name logger)
+     nil)
+    (t
+     (let ((channel (make-a-channel channel-name (formats logger) (user-output logger))))
+       (join (connection logger) channel-name)
+       (push channel (channels logger))
+       (push channel-name (channel-names logger))))))
+
+(defun remove-channel-logger (logger channel-name)
+  (let ((channel (find-channel-with-name logger channel-name)))
+    (cond
+      (channel
+       (part (connection logger) channel-name)
+       (dotimes (i (length (streams channel)))
+        (when (streamp (get-stream channel i))
+          (close (get-stream channel i))
+          (setf (get-stream channel i) nil)))
+       (setf (channels logger) (delete channel-name (channels logger)
+                                      :test #'string-equal
+                                      :key #'name))
+       (setf (channel-names logger) (delete channel-name (channel-names logger)
+                                           :test #'string-equal))
+       t)
+      (t
+       (warn "Channel name ~A not found in logger ~A." 
+            channel-name logger)
+       nil))))
+
 (defun add-hook-logger (logger class hook)
   (add-hook (connection logger) class hook))
 
 (defun remove-hook-logger (logger class hook)
   (remove-hook (connection logger) class hook))
+
+(defvar *warning-message-utime* nil)
+
+(defun kill-hook (msg)
+  (let ((target (second (arguments msg)))
+       (logger (find-logger-with-connection (connection msg))))
+    (when (and (stringp target)
+              (string-equal target (nickname logger)))
+      (setf (warning-message-utime logger) (received-time msg)))
+    (output-event msg :kill nil (format nil "~{~A~^ ~}" (arguments 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)))
+      (setf (warning-message-utime logger) (received-time msg)))
+    (output-event msg :error nil (trailing-argument msg))))
+
+(defun warning-hook (msg)
+  (let ((logger (find-logger-with-connection (connection msg))))
+    (output-event msg :server 
+                 (format nil "~{~A~^ ~} ~A)"
+                         (arguments msg)
+                         (trailing-argument msg)))
+    (when logger
+      (setf (warning-message-utime logger) (get-universal-time)))))
+  
+(defun daemon-sleep (seconds)
+  #-allegro (sleep seconds)
+  #+allegro (mp:process-sleep seconds))
+
+(defun log-disconnection (logger)
+  ;; 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)))))
+
+(defun log-reconnection (logger)
+  (log-daemon-message logger
+                     "Connection restablished at ~A." (format-date-time (get-universal-time))))
+
+(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))))
+
+
+(let (*recon-nick* *recon-server* *recon-username* *recon-realname*
+      *recon-user-output*
+      *recon-formats* *recon-async* *recon-logging-stream* *recon-channel-names*)
+  (declare (special *recon-nick* *recon-server* *recon-username* *recon-realname*
+                   *recon-formats* *recon-password* *recon-async* 
+                   *recon-user-output*
+                   *recon-logging-stream* *recon-channel-names*))
+  
+  (defun attempt-reconnection (logger)
+    (when (is-connected logger)
+      (return-from attempt-reconnection nil))
+    
+    (log-disconnection logger)
+    (when (connection logger)
+      (ignore-errors (quit (connection logger) "Client terminated by server"))
+      (setf *recon-nick* (nickname logger)
+           *recon-server* (server logger)
+           *recon-username* (username logger)
+           *recon-realname* (realname logger)
+           *recon-password* (password logger)
+           *recon-async* (async logger)
+           *recon-user-output* (user-output logger)
+           *recon-formats* (formats logger)
+           *recon-logging-stream* (logging-stream logger)
+           *recon-channel-names* (channel-names logger))
+      (ignore-errors (remove-logger logger)))
+    
+    (ignore-errors
+     (add-logger *recon-nick* *recon-server*
+                :channels *recon-channel-names*
+                :output *recon-user-output*
+                :password *recon-password*
+                :realname *recon-realname*
+                :username *recon-username*
+                :logging-stream *recon-logging-stream*
+                :async *recon-async*
+                :formats *recon-formats*)))
+  )
+
+(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)))))
+