karthink / gptel

A simple LLM client for Emacs
GNU General Public License v3.0
1.04k stars 111 forks source link

getting empty response from openai backend; response not empty #260

Closed mmwilbert closed 3 months ago

mmwilbert commented 3 months ago

This is very similar to #253, but it's happening with the GPT backend. What I see in the interface is "Empty Response". This happens in Gnu Emacs 29.2 with the only lines in the init.el file being

(setq gptel-api-key "<key>")
(setq gptel-log-level 'debug)

Note that I don't see this on all my emacs installations. On a different machine with 29.1 it works fine. But I installed 29.1 on this machine and I still get empty response. Both machines are running Ubuntu 22.04.3 LTS. The difference is that the one that works is running on a "normal" VM, and the other one is running in WSL on Windows 11. I don't know why this would affect anything, but apparently it does.

Here's the whole log:

{
  "gptel": "request headers",
  "timestamp": "2024-03-18 10:20:37"
}
{
  "Content-Type": "application/json",
  "Authorization": "Bearer sk-<REDACTED>"
}
{
  "gptel": "request body",
  "timestamp": "2024-03-18 10:20:37"
}
{
  "model": "gpt-3.5-turbo",
  "messages": [
    {
      "role": "system",
      "content": "You are a large language model living in Emacs and a helpful assistant. Respond concisely."
    },
    {
      "role": "user",
      "content": "what is a mongoose?"
    }
  ],
  "stream": true,
  "temperature": 1.0
}
{"gptel": "request Curl command", "timestamp": "2024-03-18 10:20:37"}
curl \f
--disable \
--location \
--silent \
--compressed \
-XPOST \
-y300 \
-Y1 \
-D- \
-w\(c461e236148647bc74b3aa0d138a4557\ .\ \%\{size_header\}\) \
-d\{\"model\"\:\"gpt-3.5-turbo\"\,\"messages\"\:\[\{\"role\"\:\"system\"\,\"content\"\:\"You\ are\ a\ large\ language\ model\ living\ in\ Emacs\ and\ a\ helpful\ assistant.\ Respond\ concisely.\"\}\,\{\"role\"\:\"user\"\,\"content\"\:\"what\ is\ a\ mongoose\?\"\}\]\,\"stream\"\:true\,\"temperature\"\:1.0\} \
-HContent-Type\:\ application/json \
-HAuthorization\:\ Bearer\ sk-<REDACTED> \
https\://api.openai.com/v1/chat/completions
{
  "gptel": "response headers",
  "timestamp": "2024-03-18 10:20:38"
}
"HTTP/2 200 \r\ndate: Mon, 18 Mar 2024 14:20:37 GMT\r\ncontent-type: text/event-stream\r\naccess-control-allow-origin: *\r\ncache-control: no-cache, must-revalidate\r\nopenai-model: gpt-3.5-turbo-0125\r\nopenai-organization: user-tebtekbenm9hxoxd0m1zysee\r\nopenai-processing-ms: 227\r\nopenai-version: 2020-10-01\r\nstrict-transport-security: max-age=15724800; includeSubDomains\r\nx-ratelimit-limit-requests: 10000\r\nx-ratelimit-limit-tokens: 60000\r\nx-ratelimit-remaining-requests: 9999\r\nx-ratelimit-remaining-tokens: 59954\r\nx-ratelimit-reset-requests: 8.64s\r\nx-ratelimit-reset-tokens: 46ms\r\nx-request-id: req_4781e22385cff8ee8e5511d312129047\r\ncf-cache-status: DYNAMIC\r\nset-cookie: __cf_bm=OEfXkBsGBmw2..9J6nnpJQZ64q8Q_G34MiTuWSThtR8-1710771637-1.0.1.1-Wbeq26FnZ4A7zRrsjoSkf8ipDY2zuPajIZkLgEYm90myMAqfqr85UmmZl9GkgMy714YDQ1cb7IbPTUmrjZs4ew; path=/; expires=Mon, 18-Mar-24 14:50:37 GMT; domain=.api.openai.com; HttpOnly; Secure; SameSite=None\r\nset-cookie: _cfuvid=j9PEACz78Ub.6MWKeKCK7csWGnIF_xi4IOSMpMiIcIQ-1710771637433-0.0.1.1-604800000; path=/; domain=.api.openai.com; HttpOnly; Secure; SameSite=None\r\nserver: cloudflare\r\ncf-ray: 8665dd4bca539003-BOS\r\nalt-svc: h3=\":443\"; ma=86400\r\n\r"
{
  "gptel": "response body",
  "timestamp": "2024-03-18 10:20:38"
}
data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"role":"assistant","content":""},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":"A"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" mongoose"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" is"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" a"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" small"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" carniv"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":"orous"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" mamm"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":"al"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" known"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" for"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" its"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" agility"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":","},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" ability"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" to"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" fight"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" snakes"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":","},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" and"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" social"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":" behavior"},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{"content":"."},"logprobs":null,"finish_reason":null}]}

data: {"id":"chatcmpl-9488rBZh3ttEI4nO6x86sR3wJicSq","object":"chat.completion.chunk","created":1710771637,"model":"gpt-3.5-turbo-0125","system_fingerprint":"fp_4f2ebda25a","choices":[{"index":0,"delta":{},"logprobs":null,"finish_reason":"stop"}]}

data: [DONE]
karthink commented 3 months ago

@mmwilbert I removed your API key from the log. It looks like it was visible for a few hours though, so please disable it and regenerate a new one.

This sounds like an installation problem. Before trying any other troubleshooting on the system with the problem, could you delete the gptel package and install from the latest commit?

mmwilbert commented 3 months ago

Thanks for removing the API key! OpenAI had notified me and disabled the key earlier, so it should all be good. I should have realized that I needed to scrub the log.

I tried this before, but I just removed the gptel package, checked to make sure it was gone, exited emacs, restarted emacs, reinstalled gptel, and tried it again, and I still have the same issue.

karthink commented 3 months ago

Thanks for the thorough testing there. My understanding is that the issue is on the machine with Win 11 + WSL, is that correct?

I don't know what could be causing it, but in the meantime you could try a couple of workarounds on that machine: disable streaming (setq gptel-stream nil) OR disable Curl (setq gptel-use-curl nil).

If either of these work please let me know, it will help me narrow down the possibilities.

mmwilbert commented 3 months ago

If I set either gptel-stream to nil, or gptel-use-curl to nil, the request never completes in the buffer; the state remains "Waiting". presumably because I get an error:

error in process filter: string-trim-right: Wrong type argument: stringp, nil
error in process filter: Wrong type argument: stringp, nil

(I mentioned this in my comment on issue #251)

The gptel-log looks like this:

{
  "gptel": "request headers",
  "timestamp": "2024-03-20 08:05:06"
}
{
  "Content-Type": "application/json",
  "Authorization": "no peeking"
}
{
  "gptel": "request body",
  "timestamp": "2024-03-20 08:05:06"
}
{
  "model": "gpt-3.5-turbo",
  "messages": [
    {
      "role": "system",
      "content": "You are a large language model living in Emacs and a helpful assistant. Respond concisely."
    },
    {
      "role": "user",
      "content": "what is a horseshoe crab?"
    }
  ],
  "stream": false,
  "temperature": 1.0
}
{"gptel": "request Curl command", "timestamp": "2024-03-20 08:05:06"}
curl \
--disable \
--location \
--silent \
--compressed \
-XPOST \
-y300 \
-Y1 \
-D- \
-w\(dbf77b03bb78fd4172dcd044c8f3720e\ .\ \%\{size_header\}\) \
-d\{\"model\"\:\"gpt-3.5-turbo\"\,\"messages\"\:\[\{\"role\"\:\"system\"\,\"content\"\:\"You\ are\ a\ large\ language\ model\ living\ in\ Emacs\ and\ a\ helpful\ assistant.\ Respond\ concisely.\"\}\,\{\"role\"\:\"user\"\,\"content\"\:\"what\ is\ a\ horseshoe\ crab\?\"\}\]\,\"stream\"\:false\,\"temperature\"\:1.0\} \
-HContent-Type\:\ application/json \
-HAuthorization\:\ Bearer\ no peeking \
https\://api.openai.com/v1/chat/completions
{
  "gptel": "response headers",
  "timestamp": "2024-03-20 08:05:08"
}
"HTTP/2 200 \r\ndate: Wed, 20 Mar 2024 12:05:06 GMT\r\ncontent-type: application/json\r\naccess-control-allow-origin: *\r\ncache-control: no-cache, must-revalidate\r\nopenai-model: gpt-3.5-turbo-0125\r\nopenai-organization: user-tebtekbenm9hxoxd0m1zysee\r\nopenai-processing-ms: 1034\r\nopenai-version: 2020-10-01\r\nstrict-transport-security: max-age=15724800; includeSubDomains\r\nx-ratelimit-limit-requests: 10000\r\nx-ratelimit-limit-tokens: 60000\r\nx-ratelimit-remaining-requests: 9999\r\nx-ratelimit-remaining-tokens: 59953\r\nx-ratelimit-reset-requests: 8.64s\r\nx-ratelimit-reset-tokens: 47ms\r\nx-request-id: req_f26458f07e10184a321e72417f73c396\r\ncf-cache-status: DYNAMIC\r\nset-cookie: __cf_bm=47XBk2gXJXWQ1YwIRtV0MSh_eKojB3TkoDJqeA6V9yE-1710936306-1.0.1.1-PGy.cagMayNk_R3l9KqYm8OeUwjyFCIT7gb5Ns9J6FgBYsXfZ_MYL5k7ipkQhPRiV5m53VvyURDoDuZdBZf4Ow; path=/; expires=Wed, 20-Mar-24 12:35:06 GMT; domain=.api.openai.com; HttpOnly; Secure; SameSite=None\r\nset-cookie: _cfuvid=QCyX8NM97u6hMpbyVPOK1G3OiD_pGyYP__Sk.kyhKfI-1710936306058-0.0.1.1-604800000; path=/; domain=.api.openai.com; HttpOnly; Secure; SameSite=None\r\nserver: cloudflare\r\ncf-ray: 86759181c8eb8fff-BOS\r\ncontent-encoding: br\r\nalt-svc: h3=\":443\"; ma=86400\r\n\r"
{
  "gptel": "response body",
  "timestamp": "2024-03-20 08:05:08"
}
{
  "id": "chatcmpl-94oyn5HAjzHON8mCJX8WfwuDVOahg",
  "object": "chat.completion",
  "created": 1710936305,
  "model": "gpt-3.5-turbo-0125",
  "choices": [
    {
      "index": 0,
      "message": {
        "role": "assistant",
        "content": "A horseshoe crab is a marine arthropod with a hard, horseshoe-shaped shell and a long, spike-like tail. They are often found in shallow coastal waters."
      },
      "logprobs": null,
      "finish_reason": "stop"
    }
  ],
  "usage": {
    "prompt_tokens": 38,
    "completion_tokens": 37,
    "total_tokens": 75
  },
  "system_fingerprint": "fp_4f0b692a78"
}
vkz commented 3 months ago

I'd like to confirm the exact same problems and behavior as op reported.

Tested with gptel 0.7 and then 0.8 built from master with straight.

On Mac works out of the box with Emacs 29.2 both in GUI and Terminal sessions.

On Linux: uname -a 6.1.0-17-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.69-1 (2023-12-30) x86_64 GNU/Linux

With curl:

curl --version
curl 7.88.1 (x86_64-pc-linux-gnu) libcurl/7.88.1 OpenSSL/3.0.11 zlib/1.2.13 brotli/1.0.9 zstd/1.5.4 libidn2/2.3.3 libpsl/0.21.2 (+libidn2/2.3.3) libssh2/1.10.0 nghttp2/1.52.0 librtmp/2.3 OpenLDAP/2.5.13
Release-Date: 2023-02-20, security patched: 7.88.1-10+deb12u5
Protocols: dict file ftp ftps gopher gophers http https imap imaps ldap ldaps mqtt pop3 pop3s rtmp rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS brotli GSS-API HSTS HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz NTLM NTLM_WB PSL SPNEGO SSL threadsafe TLS-SRP UnixSockets zstd

I get the exact same behavior as described on both: GNU Emacs 30.0.50 (build 1, x86_64-pc-linux-gnu) of 2024-03-09 GNU Emacs 29.2 (build 2, x86_64-pc-linux-gnu) of 2024-03-09

Log shows responses being streamed just fine, but ChatGPT buffer reports empty response.

With streaming disabled some post-processing function throws strigp, but I believe response is being received, end result is of course the same - nothing turns up in ChatGPT buffer.

With curl disabled I'me getting failed to establish connection to api.openai.com - I'm guessing because built in TLS lib is deprecated, so I'm guessing built in url flat won't work.

vkz commented 3 months ago

FWI out of curiosity I executed the same request on my (gptel works) Mac and (gptel empty response) Linux and ran ediff-buffers on the logs. Basically identical up to timestamps and ids.

With streaming disabled, string-trim fails because json parser signals an error attempting to parse body JSON. FWIW I validated the JSON it fails to parse and it is valid. No such problem under Mac. Maybe worth looking at what 'json library is doing or using behind the scene.

vkz commented 3 months ago

So with streaming disabled I believe the macro you want is something like this, then it works:

(defmacro gptel--json-read ()
  (if (fboundp 'json-parse-buffer)
      `(json-parse-buffer
        :object-type 'plist
        :null-object nil
        :false-object :json-false)
    `(progn
      (require 'json)
      (defvar json-object-type)
      (declare-function json-read "json" ())
      (let ((json-object-type 'plist))
        (json-read)))))

Or something to that effect, but definitely you want that (json-read) there. Problem, at least on my Linux box is that 'json-parse-buffer is not available, so on Mac execution takes the first branch, but on Linux (for me) it took the other branch of that if, which at least in master appears to be broken. Good question why I'm missing that `'json-parse-buffer' there. Emacs was built from source, so maybe I forgot to configure appropriate lib or smth seeing how that function is reported to be built-in C on mac.

vkz commented 3 months ago

oh lol, that also solves the streaming issue :)

vkz commented 3 months ago

With curl disabled I'me getting failed to establish connection to api.openai.com - I'm guessing because built in TLS lib is deprecated, so I'm guessing built in url flat won't work.

on Linux to work without curl, probably want to do either:

sudo apt install gnutls-bin
# or configure and build emacs --with-gnutls
karthink commented 3 months ago

So with streaming disabled I believe the macro you want is something like this, then it works:

Yikes! There is a glaring typo in gptel--json-read, it is meant to use (json-read). This branch of the code wasn't tested since every machine I tried it on has libjansson support and uses json-parse-buffer instead.

Thanks for catching this.

Please reopen this issue if the problem persists.