gptel: Add request logging (Fix #165)

* gptel.el (gptel--debug, gptel-log-level, gptel--log-buffer-name,
gptel--url-get-response, gptel--parse-response): Optionally log
all request and response data to `gptel--log-buffer-name`, with
the log level governed by `gptel-log-level`.  Obsolete
`gptel--debug`.

* gptel-curl.el (gptel-curl--log-response, gptel-curl--get-args,
gptel-curl--get-response, gptel-curl--stream-cleanup,
gptel-curl--sentinel): Add support for logging.

gptel-curl.el

@@ -60,6 +60,10 @@ PROMPTS is the data to send, TOKEN is a unique identifier."
                   (when-let ((header (gptel-backend-header gptel-backend)))
                     (if (functionp header)
                         (funcall header) header)))))
+    (when gptel-log-level
+      (when (eq gptel-log-level 'debug)
+        (gptel--log (json-encode headers) "request headers"))
+      (gptel--log data "request body"))
     (append
      gptel-curl--common-args
      (list (format "-w(%s . %%{size_header})" token))
@@ -102,8 +106,9 @@ the response is inserted into the current buffer after point."
          (stream (and gptel-stream (gptel-backend-stream gptel-backend)))
          (process (apply #'start-process "gptel-curl"
                          (generate-new-buffer "*gptel-curl*") "curl" args)))
-    (when gptel--debug
+    (when (eq gptel-log-level 'debug)
-      (message "%S" args))
+      (gptel--log (json-encode (cons "curl" args))
+                  "request Curl command"))
     (with-current-buffer (process-buffer process)
       (set-process-query-on-exit-flag process nil)
       (setf (alist-get process gptel-curl--process-alist)
@@ -139,6 +144,25 @@ the response is inserted into the current buffer after point."
                  (set-process-filter process #'gptel-curl--stream-filter))
         (set-process-sentinel process #'gptel-curl--sentinel)))))
 
+(defun gptel-curl--log-response (proc-buf proc-info)
+  "Parse response buffer PROC-BUF and log response.
+
+PROC-INFO is the plist containing process metadata."
+  (with-current-buffer proc-buf
+    (save-excursion
+      (goto-char (point-min))
+      (when (re-search-forward "
?\n
?\n" nil t)
+        (when (eq gptel-log-level 'debug)
+          (gptel--log (json-encode-string
+                       (buffer-substring-no-properties
+                        (point-min) (1- (point))))
+                      "response headers"))
+        (let ((p (point)))
+          (when (search-forward (plist-get proc-info :token) nil t)
+            (goto-char (1- (match-beginning 0)))
+            (gptel--log (buffer-substring-no-properties p (point))
+                        "response body")))))))
+
 (defun gptel-abort (buf)
   "Stop any active gptel process associated with buffer BUF."
   (interactive (list (current-buffer)))
@@ -166,9 +190,6 @@ the response is inserted into the current buffer after point."
 
 PROCESS and _STATUS are process parameters."
   (let ((proc-buf (process-buffer process)))
-    (when gptel--debug
-      (with-current-buffer proc-buf
-        (clone-buffer "*gptel-error*" 'show)))
     (let* ((info (alist-get process gptel-curl--process-alist))
            (gptel-buffer (plist-get info :buffer))
            (backend-name
@@ -179,6 +200,7 @@ PROCESS and _STATUS are process parameters."
            (http-status (plist-get info :http-status))
            (http-msg (plist-get info :status))
            response-beg response-end)
+      (when gptel-log-level (gptel-curl--log-response proc-buf info)) ;logging
       (if (equal http-status "200")
           (progn
             ;; Finish handling response
@@ -330,6 +352,7 @@ PROCESS and _STATUS are process parameters."
     (when-let* (((eq (process-status process) 'exit))
                 (proc-info (alist-get process gptel-curl--process-alist))
                 (proc-callback (plist-get proc-info :callback)))
+      (when gptel-log-level (gptel-curl--log-response proc-buf proc-info)) ;logging
       (pcase-let ((`(,response ,http-msg ,error)
                    (with-current-buffer proc-buf
                      (gptel-curl--parse-response proc-info))))

gptel.el

@@ -469,10 +469,25 @@ README for examples."
 (defvar-local gptel--num-messages-to-send nil)
 (put 'gptel--num-messages-to-send 'safe-local-variable #'always)
 
-(defvar gptel--debug nil
+(defcustom gptel-log-level nil
-  "Enable printing debug messages.
+  "Logging level for gptel.
 
-Also shows the response buffer when making requests.")
+This is one of nil or the symbols info and debug:
+
+nil: Don't log responses
+info: Log request and response bodies
+debug: Log request/response bodies, headers and all other
+       connection settings.
+
+When non-nil, information is logged to `gptel--log-buffer-name',
+which see."
+  :group 'gptel
+  :type '(choice
+          (const :tag "No logging" nil)
+          (const :tag "Limited" info)
+          (const :tag "Full" debug)))
+(make-obsolete-variable
+ 'gptel--debug 'gptel-log-level "0.6.5")
 
 (defun gptel-api-key-from-auth-source (&optional host user)
   "Lookup api key in the auth source.
@@ -1007,6 +1022,22 @@ BACKEND is the LLM backend in use.
 
 PROMPTS is the plist of previous user queries and LLM responses.")
 
+(defconst gptel--log-buffer-name "*gptel-log*"
+  "Log buffer for gptel.")
+
+(defun gptel--log (data &optional type no-json)
+  "Log DATA to `gptel--log-buffer-name'.
+
+TYPE is a label for data being logged.  DATA is assumed to be
+Valid JSON unless NO-JSON is t."
+  (with-current-buffer (get-buffer-create gptel--log-buffer-name)
+    (let ((p (goto-char (point-max))))
+      (unless (bobp) (insert "\n"))
+      (insert (format "{\"gptel\": \"%s\", " (or type "none"))
+              (format-time-string "\"timestamp\": \"%Y-%m-%d %H:%M:%S\"}\n")
+              data)
+      (unless no-json (ignore-errors (json-pretty-print p (point)))))))
+
 ;; TODO: Use `run-hook-wrapped' with an accumulator instead to handle
 ;; buffer-local hooks, etc.
 (defun gptel--transform-response (content-str buffer)
@@ -1059,6 +1090,10 @@ the response is inserted into the current buffer after point."
           (json-encode (gptel--request-data
                         gptel-backend (plist-get info :prompt)))
           'utf-8)))
+    (when gptel-log-level               ;logging
+      (when (eq gptel-log-level 'debug)
+        (gptel--log (json-encode url-request-extra-headers) "request headers"))
+      (gptel--log url-request-data "request body"))
     (url-retrieve (let ((backend-url (gptel-backend-url gptel-backend)))
                     (if (functionp backend-url)
                         (funcall backend-url) backend-url))
@@ -1082,6 +1117,8 @@ RESPONSE is the parsed JSON of the response, as a plist.
 PROC-INFO is a plist with process information and other context.
 See `gptel-curl--get-response' for its contents.")
 
+(defvar url-http-end-of-headers)
+(defvar url-http-response-status)
 (defun gptel--url-parse-response (backend response-buffer)
   "Parse response from BACKEND in RESPONSE-BUFFER."
   (when (buffer-live-p response-buffer)
@@ -1089,10 +1126,18 @@ See `gptel-curl--get-response' for its contents.")
       (with-current-buffer response-buffer
         (clone-buffer "*gptel-error*" 'show)))
     (with-current-buffer response-buffer
+      (when gptel-log-level             ;logging
+        (save-excursion
+          (goto-char url-http-end-of-headers)
+          (when (eq gptel-log-level 'debug)
+            (gptel--log (json-encode (buffer-substring-no-properties (point-min) (point)))
+                        "response headers"))
+          (gptel--log (buffer-substring-no-properties (point) (point-max))
+                      "response body")))
       (if-let* ((http-msg (string-trim (buffer-substring (line-beginning-position)
                                                          (line-end-position))))
                 (json-object-type 'plist)
-                (response (progn (forward-paragraph)
+                (response (progn (goto-char url-http-end-of-headers)
                                  (let ((json-str (decode-coding-string
                                                   (buffer-substring-no-properties (point) (point-max))
                                                   'utf-8)))
@@ -1100,7 +1145,7 @@ See `gptel-curl--get-response' for its contents.")
                                        (json-read-from-string json-str)
                                      (json-readtable-error 'json-read-error))))))
           (cond
-           ((string-match-p "200 OK" http-msg)
+           ((or (= url-http-response-status 200) (string-match-p "200 OK" http-msg))
             (list (string-trim (gptel--parse-response backend response
                                              '(:buffer response-buffer)))
                    http-msg))