Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Recently upgraded to clj-http 3.10.0 and :as :json not working #489

Closed
dakrone opened this issue May 2, 2019 · 18 comments · Fixed by #507
Closed

Recently upgraded to clj-http 3.10.0 and :as :json not working #489

dakrone opened this issue May 2, 2019 · 18 comments · Fixed by #507

Comments

@dakrone
Copy link
Owner

dakrone commented May 2, 2019

Greetings - we recently upgraded to clj-http 3.10.0. The following doesn't work in 3.10.0, but it worked in 3.9.1. In 3.10.0, we get a java.io.IOException Stream Closed error

(client/get "https://some-site.com/myresource"
            {:basic-auth       ["user" "pass"]
             :accept              :json
             **:as                     :json**
             :coerce              :always
             :throw-exceptions false})

If we remove :as :json, we don't get that error, but the body isn't coerced to a clj map. I'm planning on looking through changes leading up to 3.10.0, but before I did that, I figured that I'd post the error for early awareness.

Originally posted by @ecolui in #475 (comment)

@ghost
Copy link

ghost commented May 24, 2019

Same here:

    (:body (debug (http/get (debug (str endpoint api-path object-type))
                            (debug {:as :json
                                    :basic-auth [username password]
                                    :query-params parameters}))))))

The inner debug calls happen, but the outer throws:

                                                   clojure.core/eval                    core.clj: 3214
                                                                 ...                                  
                           phabricator-exporter-jira.core/eval111364                   REPL Input     
                      phabricator-exporter-jira.core/sync-components                    core.clj: 1226
                   phabricator-exporter-jira.core/sync-components/fn                    core.clj: 1227
                    phabricator-exporter-jira.core/get-jira-software                    core.clj: 1027
                    phabricator-exporter-jira.core/get-jira-software                    core.clj: 1029
                             phabricator-exporter-jira.core/get-jira                    core.clj: 1020
                          phabricator-exporter-jira.core/get-jira/fn                    core.clj: 1020
                                               taoensso.timbre/-log!                  timbre.clj:  358
                                                  clojure.core/deref                    core.clj: 2320
                                                                 ...                                  
                       phabricator-exporter-jira.core/get-jira/fn/fn                    core.clj: 1020
                                            puget.printer/cprint-str                 printer.clj:  716
                                            puget.printer/cprint-str                 printer.clj:  718
                                            puget.printer/pprint-str                 printer.clj:  702
                                            puget.printer/render-str                 printer.clj:  684
                                         puget.printer/render-str/fn                 printer.clj:  685
                                            puget.printer/render-out                 printer.clj:  674
                                         fipp.engine/pprint-document                 engine.cljc:  239
                                               fipp.engine/serialize                 engine.cljc:   18
                                                                 ...                                  
                                            fipp.engine/eval12550/fn                 engine.cljc:   48
                                               fipp.engine/serialize                 engine.cljc:   15               engine.cljc:   15�[m
                                                                 ...                                  
                                                 clojure.core/mapcat                    core.clj: 2783 (repeats 2 times)
                                                  clojure.core/apply                    core.clj:  660
                                                    clojure.core/seq                    core.clj:  137
                                                                 ...                                  
                                                 clojure.core/map/fn                    core.clj: 2753
                                               fipp.engine/serialize                 engine.cljc:   18
                                                                 ...                                  
                                            fipp.engine/eval12569/fn                 engine.cljc:   63
                                               fipp.engine/serialize                 engine.cljc:   15
                                                                 ...                                  
                                                 clojure.core/mapcat                    core.clj: 2783 (repeats 2 times)
                                                  clojure.core/apply                    core.clj:  660
                                                    clojure.core/seq                    core.clj:  137
                                                                 ...                                  
                                                 clojure.core/map/fn                    core.clj: 2753
                                               fipp.engine/serialize                 engine.cljc:   15
                                                                 ...                                  
                                                 clojure.core/mapcat                    core.clj: 2783 (repeats 2 times)
                                                  clojure.core/apply                    core.clj:  660
                                                    clojure.core/seq                    core.clj:  137
                                                                 ...                                  
                                                 clojure.core/map/fn                    core.clj: 2746
                                                    clojure.core/seq                    core.clj:  137
                                                                 ...                                  
                                                clojure.core/drop/fn                    core.clj: 2932
                                              clojure.core/drop/step                    core.clj: 2927
                                                    clojure.core/seq                    core.clj:  137
                                                                 ...                                  
                                          clojure.core/interleave/fn                    core.clj: 4316
                                                    clojure.core/seq                    core.clj:  137
                                                                 ...                                  
                                                 clojure.core/map/clojure.core/map/�[1;33mfn                    core.clj: 2755
                                      puget.printer.PrettyPrinter/fn                 printer.clj:  579
                                            puget.printer/format-doc                 printer.clj:  232
                                           puget.printer/format-doc*                 printer.clj:  223
                                          puget.printer/iseq-handler                 printer.clj:  314
                               puget.printer.PrettyPrinter/visit-seq                 printer.clj:  529
                                                    clojure.core/seq                    core.clj:  137
                                                                 ...                                  
                                cheshire.parse/lazily-parse-array/fn                   parse.clj:   52
                                               cheshire.parse/parse*                   parse.clj:   63 (repeats 3 times)
                                               cheshire.parse/parse*                   parse.clj:   65
       com.fasterxml.jackson.core.json.ReaderBasedJsonParser.getText  ReaderBasedJsonParser.java:  278
 com.fasterxml.jackson.core.json.ReaderBasedJsonParser._finishString  ReaderBasedJsonParser.java: 2016
com.fasterxml.jackson.core.json.ReaderBasedJsonParser._finishString2  ReaderBasedJsonParser.java: 2028
     com.fasterxml.jackson.core.json.ReaderBasedJsonParser._loadMore  ReaderBasedJsonParser.java:  243
                                         java.io.BufferedReader.read         BufferedReader.java:  279
                                   java.io.BufferedReader.ensureOpen         BufferedReader.java:  122
java.io.IOException: Stream closed

Execution error (IOException) at java.io.BufferedReader/ensureOpen (BufferedReader.java:122).
Stream closed

It works fine for the URLs which return very little data, but fetching the first URL that outputs more (5.5k characters according to http ... | wc -c) breaks in this manner.

@l3nz
Copy link

l3nz commented May 24, 2019

Same here. Weirdly, ":as :json-strict" works.

Deps:

  • [org.clojure/clojure "1.9.0"]
  • [cheshire "5.8.1"]
  • [clj-http "3.10.0"]

@jsyrjala
Copy link
Contributor

jsyrjala commented Jun 11, 2019

Same here:

  • [org.clojure/clojure "1.10.1"]
  • [clj-http "3.10.0"]
  • [cheshire "5.8.1"]

It seems that response body returned from http post function is a thing that lazily parses the stream.
Which then fails with a Stream closed Exception if the parser has not finished before the connection and the stream are closed. This doesn't happen with every request. It seems to depend on server you are connecting to (probably response times/other timings).

I replaced :as :json with this kind of thing:

  (let [response (http/post url {
                                 :content-type   :json
                                 :accept         :json
                                 :as             :byte-array
                                 :socket-timeout 5000
                                 :conn-timeout   5000})
         (let [body-string (slurp (:body response))
            body (json/parse-string body-string true)]
            ;; now body is parsed correctly without errors
         )
)

So it would seem to be a some kind of hard to hit race condition. I have been using this version of clj-http since relase in various servers without any problems. Today I hit a case where this fails about 50% of time. A server process running on a fast server was moved to small Docker container and this problem started to appear.

This kind of stack trace happens after the request is made when I am processing the body.

Stream closed: java.io.IOException
java.io.IOException: Stream closed
at java.io.BufferedReader.ensureOpen(BufferedReader.java:122)
at java.io.BufferedReader.read(BufferedReader.java:278)
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._loadMore(ReaderBasedJsonParser.java:243)
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._finishString2(ReaderBasedJsonParser.java:2028)
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._finishString(ReaderBasedJsonParser.java:2016)
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser.getText(ReaderBasedJsonParser.java:278)
at cheshire.parse$parse_STAR_.invokeStatic(parse.clj:65)
at cheshire.parse$parse_STAR_.invoke(parse.clj:61)
at cheshire.parse$parse_STAR_.invokeStatic(parse.clj:63)
at cheshire.parse$parse_STAR_.invoke(parse.clj:61)
at cheshire.parse$lazily_parse_array$fn__2278.invoke(parse.clj:52)
at clojure.lang.LazySeq.sval(LazySeq.java:42)
at clojure.lang.LazySeq.seq(LazySeq.java:51)
at clojure.lang.RT.seq(RT.java:535)
at clojure.core$seq__5402.invokeStatic(core.clj:137)
at clojure.core$filter$fn__5893.invoke(core.clj:2809)
at clojure.lang.LazySeq.sval(LazySeq.java:42)
at clojure.lang.LazySeq.seq(LazySeq.java:58)
at clojure.lang.RT.seq(RT.java:535)
at clojure.core$seq__5402.invokeStatic(core.clj:137)
at event_import.core$send_event_batch.invokeStatic(core.clj:153)
at event_import.core$send_events$fn__3341.invoke(core.clj:166)
at clojure.core$map$fn__5866.invoke(core.clj:2755)
at clojure.lang.LazySeq.sval(LazySeq.java:42)
at clojure.lang.LazySeq.seq(LazySeq.java:51)
at clojure.lang.RT.seq(RT.java:535)
at clojure.core$seq__5402.invokeStatic(core.clj:137)
at clojure.core$dorun.invokeStatic(core.clj:3133)
at event_import.core$send_events.invokeStatic(core.clj:164)
at event_import.core$lambda_handler.invokeStatic(core.clj:199)
at event_import.core$_handler.invokeStatic(core.clj:217)
at event_import.core$_handler.invoke(core.clj:217)
at event_import.core.handler(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)

@jsyrjala
Copy link
Contributor

The reason seem to be that :as :json parses lazily response bodies with JSON array at top level.
:as :json will end up calling parse-stream.
https://github.com/dakrone/cheshire/blob/master/src/cheshire/core.clj#L232

I think that :as :json should not do lazy parsing and probably it should end up calling parse-stream-strict.

@jsyrjala
Copy link
Contributor

I'll work on a PR to fix this on tomorrow.

@rymndhng
Copy link
Collaborator

rymndhng commented Aug 1, 2019

I took a deeper look at this issue, and I see two potential solutions -- both have merits, but have pros/cons for users who just want to get something done.

The current nomenclanture :json and :json-strict implies that :json could be parsed lazily. In #475, the change reduces copying, but it introduces a subtle change to the non-strict parsing. In particular, the stream is eagerly closed when the block exits. This prevents lazy decoding. See https://github.com/dakrone/clj-http/blob/3.x/src/clj_http/client.clj#L474

Here comes the options.

Option 1: Do not close .stream when using :json. This is the easy solution to fix the behaviour for existing users. The downside is that callers has to be aware of how to consume or close the stream. If they do not fully realize the stream, the connection will not be provided back to the connection pool. I have a PR open for this solution: #505

Option 2: Make :json strict by default, and introduce a new :json-stream to have a lazy parsing stream. It makes sense to be strict by default because for most users, this is what they actually want. We should make :json-stream an option for advanced users who are trying to defer the cost of parsing an array -- mainly because the caller needs to be aware of how stream consumption impacts connection pools. This is where @jsyrjala's PR was going.


From an end user POV, I would prefer option 2 because it is a much saner default. However, I think option 1 is also a nice because the fix is easy, but it has caveats of implicit connection management.

@jsyrjala
Copy link
Contributor

jsyrjala commented Aug 1, 2019

I would definitely choose option 2. This is what I would expect as a user. Also not closing connections automatically could lead to weird/hard to detect bugs.

@ignorabilis
Copy link

Just bumped into this too. I was thinking that there should be some way to close the stream only after the lazy seq has been realized, but for now I'll be using @jsyrjala slurp solution.

@rymndhng - I think that not closing the stream would be something unexpected by the user; as a rule if you created the stream you should also close it; delegating this to the user would introduce bugs.

@jsyrjala
Copy link
Contributor

jsyrjala commented Oct 22, 2019

@ignorabilis I think the easiest solution is to replace :as :json with :as :json-strict. Strict means eager (non-lazy) parsing.

@xavierchow
Copy link

xavierchow commented Dec 8, 2019

I encountered the same issue. After looking around I found it's been addressed in #507, but not merged yet, any ETA to that fix?

@dharrigan
Copy link

Hey!

This is biting me too :-( I'm trying to batch process a response that contains thousands of JSON objects and it's killing me by having the stream closed.

@dakrone please can you consider doing a release to address this issue, for your fans! :-)

@nikolinas
Copy link

nikolinas commented Apr 9, 2020

Experiencing the same issue @dakrone .
+1 for the request on getting the :json-stream working

@dakrone
Copy link
Owner Author

dakrone commented Apr 13, 2020

Sorry that this has taken so long, I've merged the PR and released 3.10.1 with the fix. Big thanks to @rymndhng for providing the fix.

@erez-rabih
Copy link

erez-rabih commented May 4, 2020

I'm with 3.10.1 and get NullPointerException when trying to us :as :json
this is the stacktrace

java.lang.NullPointerException: null
            core.clj:665 clojure.core/apply
            core.clj:660 clojure.core/apply
          client.clj:131 clj-http.client/json-decode
          client.clj:127 clj-http.client/json-decode
         RestFn.java:421 clojure.lang.RestFn.invoke
          client.clj:457 clj-http.client/decode-json-body
          client.clj:449 clj-http.client/decode-json-body
          client.clj:465 clj-http.client/coerce-json-body
          client.clj:460 clj-http.client/coerce-json-body
         RestFn.java:445 clojure.lang.RestFn.invoke
          client.clj:527 clj-http.client/fn
          client.clj:526 clj-http.client/fn
        MultiFn.java:234 clojure.lang.MultiFn.invoke
          client.clj:561 clj-http.client/output-coercion-response
          client.clj:558 clj-http.client/output-coercion-response
          client.clj:572 clj-http.client/wrap-output-coercion[fn]
          client.clj:249 clj-http.client/wrap-exceptions[fn]
          client.clj:726 clj-http.client/wrap-accept[fn]
          client.clj:748 clj-http.client/wrap-accept-encoding[fn]
          client.clj:709 clj-http.client/wrap-content-type[fn]
          client.clj:950 clj-http.client/wrap-form-params[fn]
          client.clj:984 clj-http.client/wrap-nested-params[fn]
         client.clj:1008 clj-http.client/wrap-flatten-nested-params[fn]
          client.clj:884 clj-http.client/wrap-method[fn]
         cookies.clj:131 clj-http.cookies/wrap-cookies[fn]
            links.clj:63 clj-http.links/wrap-links[fn]
         client.clj:1037 clj-http.client/wrap-unknown-host[fn]
         client.clj:1165 clj-http.client/request*
         client.clj:1158 clj-http.client/request*
         client.clj:1171 clj-http.client/get
         client.clj:1167 clj-http.client/get

@rymndhng
Copy link
Collaborator

rymndhng commented May 5, 2020

@erez-rabih What version of cheshire are you using.

I think you may be seeing a NPE because the version you are using is older than 5.9.0 which is when the the function parse-stream-strict was added.

@erez-rabih
Copy link

you are right
upgrading to [cheshire "5.10.0"] fixed the problem
is it mentioned anywhere in the docs?

@dharrigan
Copy link

Hi,

Not explicitly, but it is mentioned in the changelog: https://github.com/dakrone/clj-http/blob/3.x/changelog.org#3101

@erez-rabih
Copy link

I think we could add it to this section to be clearer about this
https://github.com/dakrone/clj-http#optional-dependencies

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
9 participants