Error while running thaw about nippy HOT 12 CLOSED

Hi adityo,

Could you get me some info on your environment, and the exact code you're trying to execute?

Thanks!

from nippy.

Hey Peter,

im currently running emacs 24, with clojure 1.5.1 , nrepl instead of slime/swank on mac osx lion.

I have been using carmine to store data into redis. On carmine "1.12.0", i was serializing a sequence of clojure maps into json and then writing to redis. each clojure map had a key whose value was a joda time date obj.

with carmine 2.0.0-beta5, nippy is also included and i thought i might give it a try (hopefully i wouldn't have to serialize my objects to json). since latest carmine fetches latest nippy i simply included it in my project. i ran the following commands on my repl.

(def frozen-stress-data (nippy/freeze nippy/stress-data)) and (nippy/thaw frozen-stress-data)

which led to the following error
CorruptionException Invalid copy offset for opcode starting at 23 org.iq80.snappy.SnappyDecompressor.decompressAllTags (SnappyDecompressor.java:165)

that is the most basic example provided on the github page.

i also tried it on my data set, the freeze command works however the thaw command causes the above error.

--regards
Adie

from nippy.

Well thanks a lot for reporting this Adie!

Not quite sure yet what the problem is since I'm struggling to reproduce it from my side.

i also tried it on my data set, the freeze command works however the thaw command causes the above error.

So you're saying you get this error for anything you freeze and try to thaw again?

Could you tell me what happens with each of the following?:

• (nippy/thaw (nippy/freeze "test"))
• (nippy/thaw (nippy/freeze "test" {:compressor nil}))
• (nippy/thaw (nippy/freeze nippy/stress-data {:compressor nil}))
• (nippy/thaw (nippy/freeze "test" {:legacy-mode true}))
• (nippy/thaw (nippy/freeze nippy/stress-data {:legacy-mode true}))

Also could you tell me what OS you're on and what version of Java you're running?

Thanks a lot for your help - really want to get to the bottom of this.

Cheers! :-)

from nippy.

Hey Peter,

I am on Mac OSX Lion and Java version is Java(TM) SE Runtime Environment (build 1.6.0_51-b11-456-11M4508)
Java HotSpot(TM) 64-Bit Server VM (build 20.51-b01-456, mixed mode)

Here are the outputs for each

• (nippy/thaw (nippy/freeze "test")) => test
• (nippy/thaw (nippy/freeze "test" {:compressor nil})) => test
• (nippy/thaw (nippy/freeze nippy/stress-data {:compressor nil})) => CorruptionException Invalid copy offset for opcode starting at 23 org.iq80.snappy.SnappyDecompressor.decompressAllTags (SnappyDecompressor.java:165)
• (nippy/thaw (nippy/freeze "test" {:legacy-mode true})) => test
• (nippy/thaw (nippy/freeze nippy/stress-data {:legacy-mode true})) = > RuntimeException EvalReader not allowed when *read-eval is false. clojure.lang.Util.runtimeException (Util.java:219)*

Additionally

Here is a sample of what im trying to freeze and thaw with the outputs i'm getting.

• (nippy/thaw (nippy/freeze {:created_at (clj-time.core/now)})) => CorruptionException Invalid copy offset for opcode starting at 60 org.iq80.snappy.SnappyDecompressor.decompressAllTags (SnappyDecompressor.java:165)

or

• (nippy/thaw (nippy/freeze {:created_at (java.util.Date.)})) => CorruptionException Invalid copy offset for opcode starting at 60 org.iq80.snappy.SnappyDecompressor.decompressAllTags (SnappyDecompressor.java:165)

--regards
Adityo

from nippy.

(nippy/thaw (nippy/freeze nippy/stress-data {:compressor nil})) => CorruptionException ...

This one is leading me to believe the issue we're seeing may be a result of some difference in the way your JVM is processing byte arrays for some reason. Almost certainly a bug on my end, but I still haven't been able to reproduce it.

I've just pushed a debug version: [com.taoensso.debug/nippy "2.0.0-beta3"] (note the changed group-id).

When you get a chance, would you mind rerunning the same tests again with this version? It'll produce some println output which you can copy me and should help diagnose the cause.

Again, thanks so much for your help with this!

from nippy.

Yeah, sorry - I'm out of ideas w/o further info. Have tried a number of JVMs and a number of datatypes w/o being able to reproduce this. Have gone over all the relevant code, and nothing's sticking out as obviously broken.

These two in particular surprise me:

• (nippy/thaw (nippy/freeze nippy/stress-data {:compressor nil})) => CorruptionException
• (nippy/thaw (nippy/freeze nippy/stress-data {:legacy-mode true})) => RuntimeException

The only way the first one can be happening is if the header is somehow corrupt (otherwise thaw wouldn't even be attempting decompression). In that case though you'd be getting an "Uncompressed data?" exception.

The second one, likewise, is confounding. There's nothing in the stress data that requires read-eval. Even if the header were corrupt (therefore corrupting the data), I don't see why this wouldn't raise the same "Uncompressed data?" exception.

Have nothing else I can think of to try on my end, so I'll wait on your response to the debug version's output.

Cheers!

from nippy.

Hey Peter,

Somehow i wasn't getting any output when using nrepl so switched to slime-repl.

Here are the following outputs.

• (nippy/thaw (nippy/freeze "test")) =>

  Wrapping freeze header: {:metadata {:compressed? true, :encrypted? false}, :meta-id 1, :head-ba [78 80 89 1]}
  Parsing thaw header: {:head-ba [78 80 89 1], :sig*-match? true, :head-meta {:encrypted? false, :compressed? true, :version 1}}
  Trying thaw: {:encrypted? false, :compressed? true, :version 1}
  "test"

• (nippy/thaw (nippy/freeze "test" {:compressor nil})) =>

  Wrapping freeze header: {:metadata {:compressed? false, :encrypted? false}, :meta-id 0, :head-ba [78 80 89 0]}
  Parsing thaw header: {:head-ba [78 80 89 0], :sig*-match? true, :head-meta {:encrypted? false, :compressed? false, :version 1}}
  Trying thaw: {:encrypted? false, :compressed? false, :version 1}
  "test"

• (nippy/thaw (nippy/freeze nippy/stress-data {:compressor nil})) =>

  Wrapping freeze header: {:metadata {:compressed? false, :encrypted? false}, :meta-id 0, :head-ba [78 80 89 0]}
  Parsing thaw header: {:head-ba [78 80 89 0], :sig*-match? true, :head-meta {:encrypted? false, :compressed? false, :version 1}}
  Trying thaw: {:encrypted? false, :compressed? false, :version 1}
  Trying thaw: nil
  ; Evaluation aborted.

• (nippy/thaw (nippy/freeze "test" {:legacy-mode true})) =>

  Parsing thaw header: {:head-ba [9 32 13 0], :sig*-match? false, :head-meta {:encrypted? false, :compressed? false, :version 1}}
  Trying thaw: nil
  "test"

• (nippy/thaw (nippy/freeze nippy/stress-data {:legacy-mode true})) =>

  EvalReader not allowed when read-eval is false.

• (nippy/thaw (nippy/freeze {:created_at (clj-time.core/now)})) =>

  Wrapping freeze header: {:metadata {:compressed? true, :encrypted? false}, :meta-id 1, :head-ba [78 80 89 1]}
  Parsing thaw header: {:head-ba [78 80 89 1], :sig*-match? true, :head-meta {:encrypted? false, :compressed? true, :version 1}}
  Trying thaw: {:encrypted? false, :compressed? true, :version 1}
  Trying thaw: nil
  ; Evaluation aborted.

i shall try and run the same on my colleague's machine as soon as i get in to work. Hope i have not messed up something on my system only.

--regards
Adityo

from nippy.

Hi Adityo, okay, that was very helpful - think we're getting somewhere!

My hunch is that you've got some kind of custom data-reader in your environment that is fiddling with the nippy/stress-data in an unexpected way. That would potentially explain every error we've seen.

Here's a (hopefully final) set of tests to run:

• (nippy/thaw (nippy/freeze (dissoc nippy/stress-data :tagged-uuid :tagged-date)))

If this one works, it confirms the diagnosis. No need to try the rest.

• (nippy/thaw (nippy/freeze (dissoc nippy/stress-data :tagged-uuid :tagged-date) {:compressor nil}))
• (nippy/thaw (nippy/freeze (dissoc nippy/stress-data :tagged-uuid :tagged-date :bytes) {:compressor nil}))
• (nippy/thaw (nippy/freeze (dissoc nippy/stress-data :tagged-uuid :tagged-date :bytes) {:compressor nil}) {:legacy-opts nil)

This one should throw an exception describing (hopefully) the actual cause, assuming my hunch above is incorrect.

If the diagnosis was confirmed:
Basically it looks like something is interfering with the way your Reader is interpreting dates. What happens if you evaluate (java.util.Date.) at the REPL? What about (read-string (pr-str (java.util.Date.)))? What is the value of your *data-readers*?

(read-string (pr-str (java.util.Date.))) should work (regardless of any custom data readers). If that's not working, then that's what you need to debug.

If the diagnosis was NOT confirmed:
Send me the output from the above tests and let's go from there.

Cheers :-)

from nippy.

Hey Peter,

Diagnosis confirmed. Something is interfering with the way my Reader is interpreting dates.

To confirm i ran a very basic project fetching only nippy as a dependency and the example
(nippy/thaw (nippy/freeze nippy/stress-data)) worked perfectly.

So some library i am fetching for my project seems to be adding in a custom reader, and we think we might have the found the problem (thanks to the efforts of my colleague Kiran).

Monger is the culprit.
https://github.com/michaelklishin/monger/blob/master/src/clojure/monger/joda_time.clj#L42

From Line 42 there are two custom print-dup, one for java.util.Date and the other for joda time object and i guess these are messing up.

I would suggest you fetch monger in your test project to confirm this behavior.

--regards
Adityo

from nippy.

Yup, that could very well be the cause (assuming you've got no other libs doing the same thing). To confirm, try: (nippy/thaw (nippy/freeze nippy/stress-data) {:read-eval true})) (it should work).

The problem is that this method is using a "#=" (reader eval) call which is normally disabled by default in Nippy for security. I'll mention this to Michael (Monger author).

from nippy.

Yes confirmed,

(nippy/thaw (nippy/freeze nippy/stress-data) {:read-eval? true}) works.

Thanks a lot for your patience.

--regards
Adityo

from nippy.

Okay, great. I would strongly recommend against using that workaround btw. Better to get the underlying problem solved. Enabling *read-eval* can expose you to serious security issues since it can allow an attacker to basically evaluate any code in your JVM instance.

Thanks a lot for your patience.

Absolutely no problem! Happy I could help :-)

from nippy.