Skip to content

Commit

Permalink
gptel: Add request logging (Fix #165)
Browse files Browse the repository at this point in the history 
* 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.
  • Loading branch information
@karthink
karthink committed Feb 3, 2024
1 parent 6a385ff commit 2c87acd
Show file tree
Hide file tree
Showing 2 changed files with 78 additions and 10 deletions.
33 changes: 28 additions & 5 deletions gptel-curl.el
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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))
Expand Down Expand Up @@ -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
(message "%S" args))
(when (eq gptel-log-level 'debug)
(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)
Expand Down Expand Up @@ -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)))
Expand Down Expand Up @@ -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
Expand All @@ -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
Expand Down Expand Up @@ -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))))
Expand Down
55 changes: 50 additions & 5 deletions gptel.el
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
"Enable printing debug messages.
(defcustom gptel-log-level nil
"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.
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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))
Expand All @@ -1082,25 +1117,35 @@ 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)
(when gptel--debug
(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)))
(condition-case nil
(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))
Expand Down

0 comments on commit 2c87acd

Please sign in to comment.